[0x0000](ConBee II): Device seen - marking the device available and resetting counter [0x0000](ConBee II): Update device availability - device available: True - new availability: True - changed: False New device 0x1bd3 (a4:c1:38:84:36:44:41:d7) joined the network [0x1bd3] Scheduling initialization Received frame on uninitialized device from ep 0 to ep 0, cluster 19: b'\x00\xd3\x1b\xd7AD6\x848\xc1\xa4\x8e' [0x1bd3:zdo] ZDO request ZDOCmd.Device_annce: [0x1BD3, a4:c1:38:84:36:44:41:d7, 142] Tries remaining: 3 [0x1bd3] Requesting 'Node Descriptor' Tries remaining: 2 [0x1bd3] Extending timeout for 0xb1 request Received frame on uninitialized device from ep 0 to ep 0, cluster 32770: b'\xb1\x00\xd3\x1b\x01@\x8eA\x11BB\x00\x00*B\x00\x00' [0x1bd3] Got Node Descriptor: NodeDescriptor(logical_type=, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=, mac_capability_flags=, manufacturer_code=4417, maximum_buffer_size=66, maximum_incoming_transfer_size=66, server_mask=10752, maximum_outgoing_transfer_size=66, descriptor_capability_field=, *allocate_address=True, *is_alternate_pan_coordinator=False, *is_coordinator=False, *is_end_device=False, *is_full_function_device=True, *is_mains_powered=True, *is_receiver_on_when_idle=True, *is_router=True, *is_security_capable=False) [0x1bd3] Discovering endpoints Tries remaining: 3 Received frame on uninitialized device from ep 0 to ep 0, cluster 32773: b'\xb3\x00\xd3\x1b\x06\x01\x02\x03\x04\x05\xf2' [0x1bd3] Discovered endpoints: [1, 2, 3, 4, 5, 242] [0x1bd3] Initializing endpoints [>, >, >, >, >, >] [0x1bd3:1] Discovering endpoint information Tries remaining: 3 Received frame on uninitialized device from ep 0 to ep 0, cluster 32772: b'\xb5\x00\xd3\x1b\x1a\x01\x04\x01\n\x01\x01\x07\x03\x00\x04\x00\x05\x00\x06\x00\x00\xe0\x01\xe0\x00\x00\x02\x19\x00\n\x00' [0x1bd3:1] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=1, profile=260, device_type=266, device_version=1, input_clusters=[3, 4, 5, 6, 57344, 57345, 0], output_clusters=[25, 10]) Unknown cluster 0xE000 Unknown cluster 0xE001 [0x1bd3:2] Discovering endpoint information Tries remaining: 3 Received frame on uninitialized device from ep 0 to ep 0, cluster 32772: b'\xb7\x00\xd3\x1b\x10\x02\x04\x01\n\x01\x01\x04\x04\x00\x05\x00\x06\x00\x01\xe0\x00' [0x1bd3:2] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=2, profile=260, device_type=266, device_version=1, input_clusters=[4, 5, 6, 57345], output_clusters=[]) Unknown cluster 0xE001 [0x1bd3:3] Discovering endpoint information Tries remaining: 3 Received frame on uninitialized device from ep 0 to ep 0, cluster 32772: b'\xb9\x00\xd3\x1b\x10\x03\x04\x01\n\x01\x01\x04\x04\x00\x05\x00\x06\x00\x01\xe0\x00' [0x1bd3:3] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=3, profile=260, device_type=266, device_version=1, input_clusters=[4, 5, 6, 57345], output_clusters=[]) Unknown cluster 0xE001 [0x1bd3:4] Discovering endpoint information Tries remaining: 3 Received frame on uninitialized device from ep 0 to ep 0, cluster 32772: b'\xbb\x00\xd3\x1b\x10\x04\x04\x01\n\x01\x01\x04\x04\x00\x05\x00\x06\x00\x01\xe0\x00' [0x1bd3:4] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=4, profile=260, device_type=266, device_version=1, input_clusters=[4, 5, 6, 57345], output_clusters=[]) Unknown cluster 0xE001 [0x1bd3:5] Discovering endpoint information Tries remaining: 3 Received frame on uninitialized device from ep 0 to ep 0, cluster 32772: b'\xbd\x00\xd3\x1b\x10\x05\x04\x01\n\x01\x01\x04\x04\x00\x05\x00\x06\x00\x01\xe0\x00' [0x1bd3:5] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=5, profile=260, device_type=266, device_version=1, input_clusters=[4, 5, 6, 57345], output_clusters=[]) Unknown cluster 0xE001 [0x1bd3:242] Discovering endpoint information Tries remaining: 3 Received frame on uninitialized device from ep 0 to ep 0, cluster 32772: b'\xbf\x00\xd3\x1b\n\xf2\xe0\xa1a\x00\x00\x00\x01!\x00' [0x1bd3:242] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=242, profile=41440, device_type=97, device_version=0, input_clusters=[], output_clusters=[33]) [0x1BD3:1:0x0000] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=193, command_id=, *is_reply=False) [0x1BD3:1:0x0000] Sending request: Read_Attributes(attribute_ids=[4, 5]) [0x1BD3:1:0x0000] Received ZCL frame: b'\x18\xc1\x01\x04\x00\x00B\x10_TZ3000_cfnprab5\x05\x00\x00B\x06TS011F' [0x1BD3:1:0x0000] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=193, command_id=1, *is_reply=True) [0x1BD3:1:0x0000] Decoded ZCL frame: Basic:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0004, status=, value=TypeValue(type=CharacterString, value='_TZ3000_cfnprab5')), ReadAttributeRecord(attrid=0x0005, status=, value=TypeValue(type=CharacterString, value='TS011F'))]) [0x1bd3] Read model 'TS011F' and manufacturer '_TZ3000_cfnprab5' from > [0x1bd3] Discovered basic device information for Device is initialized Checking quirks for _TZ3000_cfnprab5 TS011F (a4:c1:38:84:36:44:41:d7) Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because input cluster mismatch on at least one endpoint Considering Fail because endpoint list mismatch: {242, 1, 2, 3} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {242, 11} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because input cluster mismatch on at least one endpoint Considering Fail because endpoint list mismatch: {242, 1, 2, 3} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {242, 11} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {11, 13} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} 'button' component -> 'ZHAIdentifyButton' using ['identify'] 'sensor' component -> 'RSSISensor' using ['basic'] 'sensor' component -> 'LQISensor' using ['basic'] 'select' component -> 'ZHAStartupOnOffSelectEntity' using ['on_off'] 'select' component -> 'ZHAStartupOnOffSelectEntity' using ['on_off'] 'select' component -> 'ZHAStartupOnOffSelectEntity' using ['on_off'] 'select' component -> 'ZHAStartupOnOffSelectEntity' using ['on_off'] 'select' component -> 'ZHAStartupOnOffSelectEntity' using ['on_off'] device - 0x1BD3:a4:c1:38:84:36:44:41:d7 entering async_device_initialized - is_new_join: True device - 0x1BD3:a4:c1:38:84:36:44:41:d7 has joined the ZHA zigbee network [0x1BD3](TS011F): started configuration [0x1BD3:ZDO](TS011F): 'async_configure' stage succeeded Error handling '_save_attribute' event with (a4:c1:38:84:36:44:41:d7, 1, 0, 4, '_TZ3000_cfnprab5') params: FOREIGN KEY constraint failed [0x1BD3:1:0x0006]: Performing cluster binding [0x1BD3:1:0x0003]: Configuring cluster attribute reporting [0x1BD3:1:0x0003]: finished channel configuration [0x1BD3:1:0x0000]: Configuring cluster attribute reporting [0x1BD3:1:0x0000]: finished channel configuration [0x1BD3:1:0x0019]: finished channel configuration [0x1BD3:2:0x0006]: Performing cluster binding [0x1BD3:3:0x0006]: Performing cluster binding [0x1BD3:4:0x0006]: Performing cluster binding [0x1BD3:5:0x0006]: Performing cluster binding Error handling '_save_attribute' event with (a4:c1:38:84:36:44:41:d7, 1, 0, 5, 'TS011F') params: FOREIGN KEY constraint failed [0x1BD3:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS [0x1BD3:1:0x0006]: Configuring cluster attribute reporting [0x1BD3:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=205, command_id=, *is_reply=False) [0x1BD3:1:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x1bd3] Delivery error for seq # 0xc5, on endpoint id 0 cluster 0x0021: message send failure [0x1BD3:2:0x0006]: Failed to bind 'on_off' cluster: [0x1bd3:0:0x0021]: Message send failure [0x1BD3:2:0x0006]: Configuring cluster attribute reporting [0x1BD3:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=207, command_id=, *is_reply=False) [0x1BD3:2:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x1bd3] Delivery error for seq # 0xc7, on endpoint id 0 cluster 0x0021: message send failure [0x1BD3:3:0x0006]: Failed to bind 'on_off' cluster: [0x1bd3:0:0x0021]: Message send failure [0x1BD3:3:0x0006]: Configuring cluster attribute reporting [0x1BD3:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=209, command_id=, *is_reply=False) [0x1BD3:3:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x1BD3:4:0x0006]: bound 'on_off' cluster: Status.SUCCESS [0x1BD3:4:0x0006]: Configuring cluster attribute reporting [0x1BD3:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=211, command_id=, *is_reply=False) [0x1BD3:4:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x1BD3:5:0x0006]: bound 'on_off' cluster: Status.SUCCESS [0x1BD3:5:0x0006]: Configuring cluster attribute reporting [0x1BD3:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=213, command_id=, *is_reply=False) [0x1BD3:5:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x1BD3:1:0x0006] Received ZCL frame: b'\x18\xcd\x07\x00\x00\x00\x00' [0x1BD3:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=205, command_id=7, *is_reply=True) [0x1BD3:1:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0x1BD3:1:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [0x1BD3:1:0x0006]: finished channel configuration [0x1BD3:1:0x0006]: 'async_configure' stage succeeded [0x1BD3:1:0x0003]: 'async_configure' stage succeeded [0x1BD3:1:0x0000]: 'async_configure' stage succeeded [0x1BD3:1:0x0019]: 'async_configure' stage succeeded [0x1bd3] Delivery error for seq # 0xd5, on endpoint id 5 cluster 0x0006: message send failure [0x1BD3:5:0x0006]: failed to set reporting on 'on_off' cluster for: [0x1bd3:5:0x0006]: Message send failure [0x1BD3:5:0x0006]: finished channel configuration [0x1BD3:5:0x0006]: 'async_configure' stage succeeded [0x1BD3:2:0x0006] Received ZCL frame: b'\x18\xcf\x07\x00\x00\x00\x00' [0x1BD3:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=207, command_id=7, *is_reply=True) [0x1BD3:2:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0x1BD3:2:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [0x1BD3:2:0x0006]: finished channel configuration [0x1BD3:2:0x0006]: 'async_configure' stage succeeded [0x1BD3:3:0x0006] Received ZCL frame: b'\x18\xd1\x07\x00\x00\x00\x00' [0x1BD3:3:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=209, command_id=7, *is_reply=True) [0x1BD3:3:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0x1BD3:3:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [0x1BD3:3:0x0006]: finished channel configuration [0x1BD3:3:0x0006]: 'async_configure' stage succeeded [0x1BD3:4:0x0006] Received ZCL frame: b'\x18\xd3\x07\x00\x00\x00\x00' [0x1BD3:4:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=211, command_id=7, *is_reply=True) [0x1BD3:4:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0x1BD3:4:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [0x1BD3:4:0x0006]: finished channel configuration [0x1BD3:4:0x0006]: 'async_configure' stage succeeded [0x1BD3](TS011F): completed configuration [0x1BD3](TS011F): stored in registry: ZhaDeviceEntry(name='_TZ3000_cfnprab5 TS011F', ieee='a4:c1:38:84:36:44:41:d7', last_seen=1656094344.998924) [0x1BD3:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=215, command_id=64, *is_reply=False) [0x1BD3:1:0x0003] Sending request: trigger_effect(effect_id=, effect_variant=) [0x1BD3:5:0x0006] Received ZCL frame: b'\x18\xd5\x07\x00\x00\x00\x00' [0x1BD3:5:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=213, command_id=7, *is_reply=True) [0x1BD3:5:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0x1BD3:5:0x0006] Received command 0x07 (TSN 213): Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0x1BD3:1:0x0003] Received ZCL frame: b'\x18\xd7\x0b@\x00' [0x1BD3:1:0x0003] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=215, command_id=11, *is_reply=True) [0x1BD3:1:0x0003] Decoded ZCL frame: Identify:Default_Response(command_id=64, status=) [0x1BD3:1:0x0003]: executed 'trigger_effect' command with args: '(2, 0)' kwargs: '{}' result: Default_Response(command_id=64, status=) [0x1BD3](TS011F): started initialization [0x1BD3:ZDO](TS011F): 'async_initialize' stage succeeded [0x1BD3:1:0x0006]: initializing channel: from_cache: False [0x1BD3:1:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [0x1BD3:1:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [0x1BD3:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=217, command_id=, *is_reply=False) [0x1BD3:1:0x0006] Sending request: Read_Attributes(attribute_ids=[16387]) [0x1BD3:1:0x0003]: initializing channel: from_cache: False [0x1BD3:1:0x0003]: finished channel initialization [0x1BD3:1:0x0000]: initializing channel: from_cache: False [0x1BD3:1:0x0000]: finished channel initialization [0x1BD3:1:0x0019]: initializing channel: from_cache: False [0x1BD3:1:0x0019]: finished channel initialization [0x1BD3:2:0x0006]: initializing channel: from_cache: False [0x1BD3:2:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [0x1BD3:2:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [0x1BD3:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=219, command_id=, *is_reply=False) [0x1BD3:2:0x0006] Sending request: Read_Attributes(attribute_ids=[16387]) [0x1BD3:3:0x0006]: initializing channel: from_cache: False [0x1BD3:3:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [0x1BD3:3:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [0x1BD3:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=221, command_id=, *is_reply=False) [0x1BD3:3:0x0006] Sending request: Read_Attributes(attribute_ids=[16387]) [0x1BD3:4:0x0006]: initializing channel: from_cache: False [0x1BD3:4:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [0x1BD3:4:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [0x1BD3:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=223, command_id=, *is_reply=False) [0x1BD3:4:0x0006] Sending request: Read_Attributes(attribute_ids=[16387]) [0x1BD3:5:0x0006]: initializing channel: from_cache: False [0x1BD3:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [0x1BD3:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [0x1BD3:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=225, command_id=, *is_reply=False) [0x1BD3:5:0x0006] Sending request: Read_Attributes(attribute_ids=[16387]) [0x1BD3:1:0x0006] Received ZCL frame: b'\x18\xd9\x01\x03@\x86' [0x1BD3:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=217, command_id=1, *is_reply=True) [0x1BD3:1:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x4003, status=)]) [0x1BD3:1:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [0x1BD3:1:0x0006]: Reading attributes in chunks: ['on_off'] [0x1BD3:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=227, command_id=, *is_reply=False) [0x1BD3:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x1BD3:3:0x0006] Received ZCL frame: b'\x18\xdd\x01\x03@\x86' [0x1BD3:3:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=221, command_id=1, *is_reply=True) [0x1BD3:3:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x4003, status=)]) [0x1BD3:3:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [0x1BD3:3:0x0006]: Reading attributes in chunks: ['on_off'] [0x1BD3:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=229, command_id=, *is_reply=False) [0x1BD3:3:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x1BD3:4:0x0006] Received ZCL frame: b'\x18\xdf\x01\x03@\x86' [0x1BD3:4:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=223, command_id=1, *is_reply=True) [0x1BD3:4:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x4003, status=)]) [0x1BD3:5:0x0006] Received ZCL frame: b'\x18\xe1\x01\x03@\x86' [0x1BD3:5:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=225, command_id=1, *is_reply=True) [0x1BD3:5:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x4003, status=)]) [0x1BD3:4:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [0x1BD3:4:0x0006]: Reading attributes in chunks: ['on_off'] [0x1BD3:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=231, command_id=, *is_reply=False) [0x1BD3:4:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x1BD3:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [0x1BD3:5:0x0006]: Reading attributes in chunks: ['on_off'] [0x1BD3:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=233, command_id=, *is_reply=False) [0x1BD3:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x1BD3:3:0x0006] Received ZCL frame: b'\x18\xe5\x01\x00\x00\x00\x10\x01' [0x1BD3:3:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=229, command_id=1, *is_reply=True) [0x1BD3:3:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [0x1BD3:3:0x0006]: finished channel initialization [0x1BD3:3:0x0006]: 'async_initialize' stage succeeded [0x1BD3:4:0x0006] Received ZCL frame: b'\x18\xe7\x01\x00\x00\x00\x10\x01' [0x1BD3:4:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=231, command_id=1, *is_reply=True) [0x1BD3:4:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [0x1BD3:4:0x0006]: finished channel initialization [0x1BD3:4:0x0006]: 'async_initialize' stage succeeded [0x1BD3:5:0x0006] Received ZCL frame: b'\x18\xe9\x01\x00\x00\x00\x10\x01' [0x1BD3:5:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=233, command_id=1, *is_reply=True) [0x1BD3:5:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [0x1BD3:5:0x0006]: finished channel initialization [0x1BD3:5:0x0006]: 'async_initialize' stage succeeded [0x1BD3:2:0x0006] Received ZCL frame: b'\x18\xdb\x01\x03@\x86' [0x1BD3:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=219, command_id=1, *is_reply=True) [0x1BD3:2:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x4003, status=)]) [0x1BD3:2:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [0x1BD3:2:0x0006]: Reading attributes in chunks: ['on_off'] [0x1BD3:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=235, command_id=, *is_reply=False) [0x1BD3:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x1bd3:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0x1bd3:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0x1BD3:2:0x0006] Received ZCL frame: b'\x18\xeb\x01\x00\x00\x00\x10\x01' [0x1BD3:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=235, command_id=1, *is_reply=True) [0x1BD3:2:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [0x1BD3:2:0x0006]: finished channel initialization [0x1BD3:2:0x0006]: 'async_initialize' stage succeeded [0x1bd3:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0x1bd3:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0x1BD3:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x1BD3:1:0x0006]: async_initialize: retryable request #1 failed: . Retrying in 0.9s [0x1BD3:1:0x0006]: initializing channel: from_cache: False [0x1BD3:1:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [0x1BD3:1:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [0x1BD3:1:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [0x1BD3:1:0x0006]: Reading attributes in chunks: ['on_off'] [0x1BD3:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=237, command_id=, *is_reply=False) [0x1BD3:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x1BD3:1:0x0006] Received ZCL frame: b'\x18\xed\x01\x00\x00\x00\x10\x01' [0x1BD3:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=237, command_id=1, *is_reply=True) [0x1BD3:1:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [0x1BD3:1:0x0006]: finished channel initialization [0x1BD3:1:0x0006]: 'async_initialize' stage succeeded [0x1BD3:1:0x0003]: 'async_initialize' stage succeeded [0x1BD3:1:0x0000]: 'async_initialize' stage succeeded [0x1BD3:1:0x0019]: 'async_initialize' stage succeeded [0x1BD3](TS011F): power source: Mains [0x1BD3](TS011F): completed initialization start_up_on_off is not supported - skipping ZHAStartupOnOffSelectEntity entity creation start_up_on_off is not supported - skipping ZHAStartupOnOffSelectEntity entity creation start_up_on_off is not supported - skipping ZHAStartupOnOffSelectEntity entity creation start_up_on_off is not supported - skipping ZHAStartupOnOffSelectEntity entity creation start_up_on_off is not supported - skipping ZHAStartupOnOffSelectEntity entity creation [0x1bd3:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0x1bd3:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0x1bd3:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0x1bd3:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) Device 0x354b (a4:c1:38:84:36:44:41:d7) joined the network Device a4:c1:38:84:36:44:41:d7 changed id (0x354b => 0x354b) [0x354b] Skipping initialization, device is fully initialized Device is initialized Checking quirks for _TZ3000_cfnprab5 TS011F (a4:c1:38:84:36:44:41:d7) Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because input cluster mismatch on at least one endpoint Considering Fail because endpoint list mismatch: {242, 1, 2, 3} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {242, 11} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because input cluster mismatch on at least one endpoint Considering Fail because endpoint list mismatch: {242, 1, 2, 3} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {242, 11} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {11, 13} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} [0x354b:zdo] ZDO request ZDOCmd.Device_annce: [0x354B, a4:c1:38:84:36:44:41:d7, 142] device - 13643:a4:c1:38:84:36:44:41:d7 entering async_device_initialized - is_new_join: False device - 13643:a4:c1:38:84:36:44:41:d7 has been reset and re-added or its nwk address changed skipping discovery for previously discovered device - 13643:a4:c1:38:84:36:44:41:d7 [13643](TS011F): started configuration [13643:ZDO](TS011F): 'async_configure' stage succeeded [13643:1:0x0006]: Performing cluster binding [13643:1:0x0003]: Configuring cluster attribute reporting [13643:1:0x0003]: finished channel configuration [13643:1:0x0000]: Configuring cluster attribute reporting [13643:1:0x0000]: finished channel configuration [13643:1:0x0019]: finished channel configuration [13643:2:0x0006]: Performing cluster binding [13643:3:0x0006]: Performing cluster binding [13643:4:0x0006]: Performing cluster binding [13643:5:0x0006]: Performing cluster binding [0x354b] Delivery error for seq # 0xf3, on endpoint id 0 cluster 0x0021: message send failure [13643:3:0x0006]: Failed to bind 'on_off' cluster: [0x354b:0:0x0021]: Message send failure [13643:3:0x0006]: Configuring cluster attribute reporting [0x354B:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=249, command_id=, *is_reply=False) [0x354B:3:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x354b] Delivery error for seq # 0xf5, on endpoint id 0 cluster 0x0021: message send failure [13643:4:0x0006]: Failed to bind 'on_off' cluster: [0x354b:0:0x0021]: Message send failure [13643:4:0x0006]: Configuring cluster attribute reporting [0x354B:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=251, command_id=, *is_reply=False) [0x354B:4:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x354b] Delivery error for seq # 0xf7, on endpoint id 0 cluster 0x0021: message send failure [13643:5:0x0006]: Failed to bind 'on_off' cluster: [0x354b:0:0x0021]: Message send failure [13643:5:0x0006]: Configuring cluster attribute reporting [0x354B:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=253, command_id=, *is_reply=False) [0x354B:5:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [13643:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS [13643:1:0x0006]: Configuring cluster attribute reporting [0x354B:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=255, command_id=, *is_reply=False) [0x354B:1:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x354b] Delivery error for seq # 0xf9, on endpoint id 3 cluster 0x0006: message send failure [13643:3:0x0006]: failed to set reporting on 'on_off' cluster for: [0x354b:3:0x0006]: Message send failure [13643:3:0x0006]: finished channel configuration [13643:3:0x0006]: 'async_configure' stage succeeded [13643:2:0x0006]: bound 'on_off' cluster: Status.SUCCESS [13643:2:0x0006]: Configuring cluster attribute reporting [0x354B:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=1, command_id=, *is_reply=False) [0x354B:2:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x354b:zdo] ZDO request ZDOCmd.Bind_rsp: [] [0x354b:zdo] No handler for ZDO request:ZDOCmd.Bind_rsp([]) [0x354b:zdo] ZDO request ZDOCmd.Bind_rsp: [] [0x354b:zdo] No handler for ZDO request:ZDOCmd.Bind_rsp([]) [0x354B:4:0x0006] Received ZCL frame: b'\x18\xfb\x07\x00\x00\x00\x00' [0x354B:4:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=251, command_id=7, *is_reply=True) [0x354B:4:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [13643:4:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [13643:4:0x0006]: finished channel configuration [13643:4:0x0006]: 'async_configure' stage succeeded [0x354b] Delivery error for seq # 0xfd, on endpoint id 5 cluster 0x0006: message send failure [13643:5:0x0006]: failed to set reporting on 'on_off' cluster for: [0x354b:5:0x0006]: Message send failure [13643:5:0x0006]: finished channel configuration [13643:5:0x0006]: 'async_configure' stage succeeded [0x354B:5:0x0006] Received ZCL frame: b'\x18\xfd\x07\x00\x00\x00\x00' [0x354B:5:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=253, command_id=7, *is_reply=True) [0x354B:5:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0x354B:5:0x0006] Received command 0x07 (TSN 253): Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0x354B:1:0x0006] Received ZCL frame: b'\x18\xff\x07\x00\x00\x00\x00' [0x354B:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=255, command_id=7, *is_reply=True) [0x354B:1:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [13643:1:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [13643:1:0x0006]: finished channel configuration [13643:1:0x0006]: 'async_configure' stage succeeded [13643:1:0x0003]: 'async_configure' stage succeeded [13643:1:0x0000]: 'async_configure' stage succeeded [13643:1:0x0019]: 'async_configure' stage succeeded [0x354B:2:0x0006] Received ZCL frame: b'\x18\x01\x07\x00\x00\x00\x00' [0x354B:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=1, command_id=7, *is_reply=True) [0x354B:2:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [13643:2:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [13643:2:0x0006]: finished channel configuration [13643:2:0x0006]: 'async_configure' stage succeeded [13643](TS011F): completed configuration [13643](TS011F): stored in registry: ZhaDeviceEntry(name='_TZ3000_cfnprab5 TS011F', ieee='a4:c1:38:84:36:44:41:d7', last_seen=1656094369.403295) [0x354B:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=3, command_id=64, *is_reply=False) [0x354B:1:0x0003] Sending request: trigger_effect(effect_id=, effect_variant=) [0x354B:1:0x0003] Received ZCL frame: b'\x18\x03\x0b@\x00' [0x354B:1:0x0003] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=3, command_id=11, *is_reply=True) [0x354B:1:0x0003] Decoded ZCL frame: Identify:Default_Response(command_id=64, status=) [13643:1:0x0003]: executed 'trigger_effect' command with args: '(2, 0)' kwargs: '{}' result: Default_Response(command_id=64, status=) [13643](TS011F): Update device availability - device available: False - new availability: True - changed: True [13643](TS011F): Device availability changed and device became available, reinitializing channels [13643](TS011F): started initialization [13643:ZDO](TS011F): 'async_initialize' stage succeeded [13643:1:0x0006]: initializing channel: from_cache: False [13643:1:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [13643:1:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [13643:1:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [13643:1:0x0006]: Reading attributes in chunks: ['on_off'] [0x354B:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=5, command_id=, *is_reply=False) [0x354B:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [13643:1:0x0003]: initializing channel: from_cache: False [13643:1:0x0003]: finished channel initialization [13643:1:0x0000]: initializing channel: from_cache: False [13643:1:0x0000]: finished channel initialization [13643:1:0x0019]: initializing channel: from_cache: False [13643:1:0x0019]: finished channel initialization [13643:2:0x0006]: initializing channel: from_cache: False [13643:2:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [13643:2:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [13643:2:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [13643:2:0x0006]: Reading attributes in chunks: ['on_off'] [0x354B:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=7, command_id=, *is_reply=False) [0x354B:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [13643:3:0x0006]: initializing channel: from_cache: False [13643:3:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [13643:3:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [13643:3:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [13643:3:0x0006]: Reading attributes in chunks: ['on_off'] [0x354B:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=9, command_id=, *is_reply=False) [0x354B:3:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [13643:4:0x0006]: initializing channel: from_cache: False [13643:4:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [13643:4:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [13643:4:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [13643:4:0x0006]: Reading attributes in chunks: ['on_off'] [0x354B:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=11, command_id=, *is_reply=False) [0x354B:4:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [13643:5:0x0006]: initializing channel: from_cache: False [13643:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [13643:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [13643:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [13643:5:0x0006]: Reading attributes in chunks: ['on_off'] [0x354B:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=13, command_id=, *is_reply=False) [0x354B:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x354B:1:0x0006] Received ZCL frame: b'\x18\x05\x01\x00\x00\x00\x10\x01' [0x354B:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=5, command_id=1, *is_reply=True) [0x354B:1:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [13643:1:0x0006]: finished channel initialization [13643:1:0x0006]: 'async_initialize' stage succeeded [13643:1:0x0003]: 'async_initialize' stage succeeded [13643:1:0x0000]: 'async_initialize' stage succeeded [13643:1:0x0019]: 'async_initialize' stage succeeded [0x354B:2:0x0006] Received ZCL frame: b'\x18\x07\x01\x00\x00\x00\x10\x01' [0x354B:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=7, command_id=1, *is_reply=True) [0x354B:2:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [13643:2:0x0006]: finished channel initialization [13643:2:0x0006]: 'async_initialize' stage succeeded [0x354B:3:0x0006] Received ZCL frame: b'\x18\t\x01\x00\x00\x00\x10\x01' [0x354B:3:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=9, command_id=1, *is_reply=True) [0x354B:3:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [13643:3:0x0006]: finished channel initialization [13643:3:0x0006]: 'async_initialize' stage succeeded [0x354B:4:0x0006] Received ZCL frame: b'\x18\x0b\x01\x00\x00\x00\x10\x01' [0x354B:4:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=11, command_id=1, *is_reply=True) [0x354B:4:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [13643:4:0x0006]: finished channel initialization [13643:4:0x0006]: 'async_initialize' stage succeeded [0x354b:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0x354b:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0x354b:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0x354b:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0x354b:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0x354b:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [13643:5:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [13643:5:0x0006]: async_initialize: retryable request #1 failed: . Retrying in 0.8s [0x354b:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0x354b:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [13643:5:0x0006]: initializing channel: from_cache: False [13643:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [13643:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [13643:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [13643:5:0x0006]: Reading attributes in chunks: ['on_off'] [0x354B:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=15, command_id=, *is_reply=False) [0x354B:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x354B:5:0x0006] Received ZCL frame: b'\x18\x0f\x01\x00\x00\x00\x10\x01' [0x354B:5:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=15, command_id=1, *is_reply=True) [0x354B:5:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [13643:5:0x0006]: finished channel initialization [13643:5:0x0006]: 'async_initialize' stage succeeded [13643](TS011F): power source: Mains [13643](TS011F): completed initialization Device 0xbd57 (a4:c1:38:84:36:44:41:d7) joined the network Device a4:c1:38:84:36:44:41:d7 changed id (0xbd57 => 0xbd57) [0xbd57] Skipping initialization, device is fully initialized Device is initialized Checking quirks for _TZ3000_cfnprab5 TS011F (a4:c1:38:84:36:44:41:d7) Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because input cluster mismatch on at least one endpoint Considering Fail because endpoint list mismatch: {242, 1, 2, 3} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {242, 11} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because input cluster mismatch on at least one endpoint Considering Fail because endpoint list mismatch: {242, 1, 2, 3} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {242, 11} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {11, 13} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} [0xbd57:zdo] ZDO request ZDOCmd.Device_annce: [0xBD57, a4:c1:38:84:36:44:41:d7, 142] device - 48471:a4:c1:38:84:36:44:41:d7 entering async_device_initialized - is_new_join: False device - 48471:a4:c1:38:84:36:44:41:d7 has been reset and re-added or its nwk address changed skipping discovery for previously discovered device - 48471:a4:c1:38:84:36:44:41:d7 [48471](TS011F): started configuration [48471:ZDO](TS011F): 'async_configure' stage succeeded [48471:1:0x0006]: Performing cluster binding [48471:1:0x0003]: Configuring cluster attribute reporting [48471:1:0x0003]: finished channel configuration [48471:1:0x0000]: Configuring cluster attribute reporting [48471:1:0x0000]: finished channel configuration [48471:1:0x0019]: finished channel configuration [48471:2:0x0006]: Performing cluster binding [48471:3:0x0006]: Performing cluster binding [48471:4:0x0006]: Performing cluster binding [48471:5:0x0006]: Performing cluster binding [0xbd57] Delivery error for seq # 0x13, on endpoint id 0 cluster 0x0021: message send failure [48471:2:0x0006]: Failed to bind 'on_off' cluster: [0xbd57:0:0x0021]: Message send failure [48471:2:0x0006]: Configuring cluster attribute reporting [0xBD57:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=27, command_id=, *is_reply=False) [0xBD57:2:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0xbd57] Delivery error for seq # 0x19, on endpoint id 0 cluster 0x0021: message send failure [48471:5:0x0006]: Failed to bind 'on_off' cluster: [0xbd57:0:0x0021]: Message send failure [48471:5:0x0006]: Configuring cluster attribute reporting [0xBD57:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=29, command_id=, *is_reply=False) [0xBD57:5:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0xbd57] Delivery error for seq # 0x1b, on endpoint id 2 cluster 0x0006: message send failure [48471:2:0x0006]: failed to set reporting on 'on_off' cluster for: [0xbd57:2:0x0006]: Message send failure [48471:2:0x0006]: finished channel configuration [48471:2:0x0006]: 'async_configure' stage succeeded [48471:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS [48471:1:0x0006]: Configuring cluster attribute reporting [0xBD57:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=31, command_id=, *is_reply=False) [0xBD57:1:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [48471:3:0x0006]: bound 'on_off' cluster: Status.SUCCESS [48471:3:0x0006]: Configuring cluster attribute reporting [0xBD57:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=33, command_id=, *is_reply=False) [0xBD57:3:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [48471:4:0x0006]: bound 'on_off' cluster: Status.SUCCESS [48471:4:0x0006]: Configuring cluster attribute reporting [0xBD57:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=35, command_id=, *is_reply=False) [0xBD57:4:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0xbd57:zdo] ZDO request ZDOCmd.Bind_rsp: [] [0xbd57:zdo] No handler for ZDO request:ZDOCmd.Bind_rsp([]) [0xBD57:5:0x0006] Received ZCL frame: b'\x18\x1d\x07\x00\x00\x00\x00' [0xBD57:5:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=29, command_id=7, *is_reply=True) [0xBD57:5:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [48471:5:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [48471:5:0x0006]: finished channel configuration [48471:5:0x0006]: 'async_configure' stage succeeded [0xBD57:1:0x0006] Received ZCL frame: b'\x18\x1f\x07\x00\x00\x00\x00' [0xBD57:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=31, command_id=7, *is_reply=True) [0xBD57:1:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [48471:1:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [48471:1:0x0006]: finished channel configuration [48471:1:0x0006]: 'async_configure' stage succeeded [48471:1:0x0003]: 'async_configure' stage succeeded [48471:1:0x0000]: 'async_configure' stage succeeded [48471:1:0x0019]: 'async_configure' stage succeeded [0xBD57:3:0x0006] Received ZCL frame: b'\x18!\x07\x00\x00\x00\x00' [0xBD57:3:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=33, command_id=7, *is_reply=True) [0xBD57:3:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [48471:3:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [48471:3:0x0006]: finished channel configuration [48471:3:0x0006]: 'async_configure' stage succeeded [0xBD57:4:0x0006] Received ZCL frame: b'\x18#\x07\x00\x00\x00\x00' [0xBD57:4:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=35, command_id=7, *is_reply=True) [0xBD57:4:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [48471:4:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [48471:4:0x0006]: finished channel configuration [48471:4:0x0006]: 'async_configure' stage succeeded [48471](TS011F): completed configuration [48471](TS011F): stored in registry: ZhaDeviceEntry(name='_TZ3000_cfnprab5 TS011F', ieee='a4:c1:38:84:36:44:41:d7', last_seen=1656094381.351601) [0xBD57:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=37, command_id=64, *is_reply=False) [0xBD57:1:0x0003] Sending request: trigger_effect(effect_id=, effect_variant=) [0xBD57:1:0x0003] Received ZCL frame: b'\x18%\x0b@\x00' [0xBD57:1:0x0003] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=37, command_id=11, *is_reply=True) [0xBD57:1:0x0003] Decoded ZCL frame: Identify:Default_Response(command_id=64, status=) [48471:1:0x0003]: executed 'trigger_effect' command with args: '(2, 0)' kwargs: '{}' result: Default_Response(command_id=64, status=) [48471](TS011F): Update device availability - device available: False - new availability: True - changed: True [48471](TS011F): Device availability changed and device became available, reinitializing channels [48471](TS011F): started initialization [48471:ZDO](TS011F): 'async_initialize' stage succeeded [48471:1:0x0006]: initializing channel: from_cache: False [48471:1:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [48471:1:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [48471:1:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [48471:1:0x0006]: Reading attributes in chunks: ['on_off'] [0xBD57:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=39, command_id=, *is_reply=False) [0xBD57:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [48471:1:0x0003]: initializing channel: from_cache: False [48471:1:0x0003]: finished channel initialization [48471:1:0x0000]: initializing channel: from_cache: False [48471:1:0x0000]: finished channel initialization [48471:1:0x0019]: initializing channel: from_cache: False [48471:1:0x0019]: finished channel initialization [48471:2:0x0006]: initializing channel: from_cache: False [48471:2:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [48471:2:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [48471:2:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [48471:2:0x0006]: Reading attributes in chunks: ['on_off'] [0xBD57:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=41, command_id=, *is_reply=False) [0xBD57:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [48471:3:0x0006]: initializing channel: from_cache: False [48471:3:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [48471:3:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [48471:3:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [48471:3:0x0006]: Reading attributes in chunks: ['on_off'] [0xBD57:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=43, command_id=, *is_reply=False) [0xBD57:3:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [48471:4:0x0006]: initializing channel: from_cache: False [48471:4:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [48471:4:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [48471:4:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [48471:4:0x0006]: Reading attributes in chunks: ['on_off'] [0xBD57:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=45, command_id=, *is_reply=False) [0xBD57:4:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [48471:5:0x0006]: initializing channel: from_cache: False [48471:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [48471:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [48471:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [48471:5:0x0006]: Reading attributes in chunks: ['on_off'] [0xBD57:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=47, command_id=, *is_reply=False) [0xBD57:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0xBD57:1:0x0006] Received ZCL frame: b"\x18'\x01\x00\x00\x00\x10\x01" [0xBD57:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=39, command_id=1, *is_reply=True) [0xBD57:1:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [48471:1:0x0006]: finished channel initialization [48471:1:0x0006]: 'async_initialize' stage succeeded [48471:1:0x0003]: 'async_initialize' stage succeeded [48471:1:0x0000]: 'async_initialize' stage succeeded [48471:1:0x0019]: 'async_initialize' stage succeeded [0xBD57:2:0x0006] Received ZCL frame: b'\x18)\x01\x00\x00\x00\x10\x01' [0xBD57:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=41, command_id=1, *is_reply=True) [0xBD57:2:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [48471:2:0x0006]: finished channel initialization [48471:2:0x0006]: 'async_initialize' stage succeeded [0xBD57:3:0x0006] Received ZCL frame: b'\x18+\x01\x00\x00\x00\x10\x01' [0xBD57:3:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=43, command_id=1, *is_reply=True) [0xBD57:3:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [48471:3:0x0006]: finished channel initialization [48471:3:0x0006]: 'async_initialize' stage succeeded [0xBD57:4:0x0006] Received ZCL frame: b'\x18-\x01\x00\x00\x00\x10\x01' [0xBD57:4:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=45, command_id=1, *is_reply=True) [0xBD57:4:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [48471:4:0x0006]: finished channel initialization [48471:4:0x0006]: 'async_initialize' stage succeeded [0xE612](lumi.sensor_magnet.aq2): Device seen - marking the device available and resetting counter [0xE612](lumi.sensor_magnet.aq2): Update device availability - device available: True - new availability: True - changed: False [0xbd57:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0xbd57:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0xbd57:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0xbd57:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0xbd57:zdo] ZDO request ZDOCmd.Bind_rsp: [] [0xbd57:zdo] No handler for ZDO request:ZDOCmd.Bind_rsp([]) [0xbd57:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0xbd57:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0xbd57:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0xbd57:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [48471:5:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [48471:5:0x0006]: async_initialize: retryable request #1 failed: . Retrying in 1.2s [48471:5:0x0006]: initializing channel: from_cache: False [48471:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [48471:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [48471:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [48471:5:0x0006]: Reading attributes in chunks: ['on_off'] [0xBD57:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=49, command_id=, *is_reply=False) [0xBD57:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0xbd57] Delivery error for seq # 0x31, on endpoint id 5 cluster 0x0006: message send failure [48471:5:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0xbd57:5:0x0006]: Message send failure [48471:5:0x0006]: async_initialize: retryable request #2 failed: [0xbd57:5:0x0006]: Message send failure. Retrying in 0.8s [48471:5:0x0006]: initializing channel: from_cache: False [48471:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [48471:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [48471:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [48471:5:0x0006]: Reading attributes in chunks: ['on_off'] [0xBD57:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=51, command_id=, *is_reply=False) [0xBD57:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0xbd57] Delivery error for seq # 0x33, on endpoint id 5 cluster 0x0006: message send failure [48471:5:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0xbd57:5:0x0006]: Message send failure [48471:5:0x0006]: async_initialize: retryable request #3 failed: [0xbd57:5:0x0006]: Message send failure. Retrying in 2.8s Device 0xb53f (a4:c1:38:84:36:44:41:d7) joined the network Device a4:c1:38:84:36:44:41:d7 changed id (0xb53f => 0xb53f) [0xb53f] Skipping initialization, device is fully initialized Device is initialized Checking quirks for _TZ3000_cfnprab5 TS011F (a4:c1:38:84:36:44:41:d7) Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because input cluster mismatch on at least one endpoint Considering Fail because endpoint list mismatch: {242, 1, 2, 3} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {242, 11} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because input cluster mismatch on at least one endpoint Considering Fail because endpoint list mismatch: {242, 1, 2, 3} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {242, 11} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {11, 13} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} [0xb53f:zdo] ZDO request ZDOCmd.Device_annce: [0xB53F, a4:c1:38:84:36:44:41:d7, 142] device - 46399:a4:c1:38:84:36:44:41:d7 entering async_device_initialized - is_new_join: False device - 46399:a4:c1:38:84:36:44:41:d7 has been reset and re-added or its nwk address changed skipping discovery for previously discovered device - 46399:a4:c1:38:84:36:44:41:d7 [46399](TS011F): started configuration [46399:ZDO](TS011F): 'async_configure' stage succeeded [46399:1:0x0006]: Performing cluster binding [46399:1:0x0003]: Configuring cluster attribute reporting [46399:1:0x0003]: finished channel configuration [46399:1:0x0000]: Configuring cluster attribute reporting [46399:1:0x0000]: finished channel configuration [46399:1:0x0019]: finished channel configuration [46399:2:0x0006]: Performing cluster binding [46399:3:0x0006]: Performing cluster binding [46399:4:0x0006]: Performing cluster binding [46399:5:0x0006]: Performing cluster binding [0xb53f] Delivery error for seq # 0x37, on endpoint id 0 cluster 0x0021: message send failure [46399:2:0x0006]: Failed to bind 'on_off' cluster: [0xb53f:0:0x0021]: Message send failure [46399:2:0x0006]: Configuring cluster attribute reporting [0xB53F:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=63, command_id=, *is_reply=False) [0xB53F:2:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [46399:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS [46399:1:0x0006]: Configuring cluster attribute reporting [0xB53F:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=65, command_id=, *is_reply=False) [0xB53F:1:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0xb53f] Delivery error for seq # 0x3f, on endpoint id 2 cluster 0x0006: message send failure [46399:2:0x0006]: failed to set reporting on 'on_off' cluster for: [0xb53f:2:0x0006]: Message send failure [46399:2:0x0006]: finished channel configuration [46399:2:0x0006]: 'async_configure' stage succeeded [0xb53f:zdo] ZDO request ZDOCmd.Bind_rsp: [] [0xb53f:zdo] No handler for ZDO request:ZDOCmd.Bind_rsp([]) [46399:3:0x0006]: bound 'on_off' cluster: Status.SUCCESS [46399:3:0x0006]: Configuring cluster attribute reporting [0xB53F:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=67, command_id=, *is_reply=False) [0xB53F:3:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [46399:4:0x0006]: bound 'on_off' cluster: Status.SUCCESS [46399:4:0x0006]: Configuring cluster attribute reporting [0xB53F:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=69, command_id=, *is_reply=False) [0xB53F:4:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0xb53f] Delivery error for seq # 0x45, on endpoint id 4 cluster 0x0006: message send failure [46399:4:0x0006]: failed to set reporting on 'on_off' cluster for: [0xb53f:4:0x0006]: Message send failure [46399:4:0x0006]: finished channel configuration [46399:4:0x0006]: 'async_configure' stage succeeded [46399:5:0x0006]: bound 'on_off' cluster: Status.SUCCESS [46399:5:0x0006]: Configuring cluster attribute reporting [0xB53F:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=71, command_id=, *is_reply=False) [0xB53F:5:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0xb53f] Delivery error for seq # 0x47, on endpoint id 5 cluster 0x0006: message send failure [46399:5:0x0006]: failed to set reporting on 'on_off' cluster for: [0xb53f:5:0x0006]: Message send failure [46399:5:0x0006]: finished channel configuration [46399:5:0x0006]: 'async_configure' stage succeeded [46399:5:0x0006]: initializing channel: from_cache: False [46399:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [46399:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [46399:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [46399:5:0x0006]: Reading attributes in chunks: ['on_off'] [0xB53F:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=73, command_id=, *is_reply=False) [0xB53F:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0xB53F:1:0x0006] Received ZCL frame: b'\x18A\x07\x00\x00\x00\x00' [0xB53F:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=65, command_id=7, *is_reply=True) [0xB53F:1:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [46399:1:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [46399:1:0x0006]: finished channel configuration [46399:1:0x0006]: 'async_configure' stage succeeded [46399:1:0x0003]: 'async_configure' stage succeeded [46399:1:0x0000]: 'async_configure' stage succeeded [46399:1:0x0019]: 'async_configure' stage succeeded [0xB53F:3:0x0006] Received ZCL frame: b'\x18C\x07\x00\x00\x00\x00' [0xB53F:3:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=67, command_id=7, *is_reply=True) [0xB53F:3:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [46399:3:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=0)] [46399:3:0x0006]: finished channel configuration [46399:3:0x0006]: 'async_configure' stage succeeded [46399](TS011F): completed configuration [46399](TS011F): stored in registry: ZhaDeviceEntry(name='_TZ3000_cfnprab5 TS011F', ieee='a4:c1:38:84:36:44:41:d7', last_seen=1656094391.5807) [0xB53F:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=75, command_id=64, *is_reply=False) [0xB53F:1:0x0003] Sending request: trigger_effect(effect_id=, effect_variant=) [0xB53F:4:0x0006] Received ZCL frame: b'\x18E\x07\x00\x00\x00\x00' [0xB53F:4:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=69, command_id=7, *is_reply=True) [0xB53F:4:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0xB53F:4:0x0006] Received command 0x07 (TSN 69): Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0xB53F:5:0x0006] Received ZCL frame: b'\x18G\x07\x00\x00\x00\x00' [0xB53F:5:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=71, command_id=7, *is_reply=True) [0xB53F:5:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0xB53F:5:0x0006] Received command 0x07 (TSN 71): Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=0)]) [0xB53F:5:0x0006] Received ZCL frame: b'\x18I\x01\x00\x00\x00\x10\x01' [0xB53F:5:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=73, command_id=1, *is_reply=True) [0xB53F:5:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [46399:5:0x0006]: finished channel initialization [46399:5:0x0006]: 'async_initialize' stage succeeded [0xB53F:1:0x0003] Received ZCL frame: b'\x18K\x0b@\x00' [0xB53F:1:0x0003] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=75, command_id=11, *is_reply=True) [0xB53F:1:0x0003] Decoded ZCL frame: Identify:Default_Response(command_id=64, status=) [46399](TS011F): power source: Mains [46399](TS011F): completed initialization [46399:1:0x0003]: executed 'trigger_effect' command with args: '(2, 0)' kwargs: '{}' result: Default_Response(command_id=64, status=) [46399](TS011F): Update device availability - device available: False - new availability: True - changed: True [46399](TS011F): Device availability changed and device became available, reinitializing channels [46399](TS011F): started initialization [46399:ZDO](TS011F): 'async_initialize' stage succeeded [46399:1:0x0006]: initializing channel: from_cache: False [46399:1:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [46399:1:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [46399:1:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [46399:1:0x0006]: Reading attributes in chunks: ['on_off'] [0xB53F:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=77, command_id=, *is_reply=False) [0xB53F:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [46399:1:0x0003]: initializing channel: from_cache: False [46399:1:0x0003]: finished channel initialization [46399:1:0x0000]: initializing channel: from_cache: False [46399:1:0x0000]: finished channel initialization [46399:1:0x0019]: initializing channel: from_cache: False [46399:1:0x0019]: finished channel initialization [46399:2:0x0006]: initializing channel: from_cache: False [46399:2:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [46399:2:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [46399:2:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [46399:2:0x0006]: Reading attributes in chunks: ['on_off'] [0xB53F:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=79, command_id=, *is_reply=False) [0xB53F:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [46399:3:0x0006]: initializing channel: from_cache: False [46399:3:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [46399:3:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [46399:3:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [46399:3:0x0006]: Reading attributes in chunks: ['on_off'] [0xB53F:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=81, command_id=, *is_reply=False) [0xB53F:3:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [46399:4:0x0006]: initializing channel: from_cache: False [46399:4:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [46399:4:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [46399:4:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [46399:4:0x0006]: Reading attributes in chunks: ['on_off'] [0xB53F:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=83, command_id=, *is_reply=False) [0xB53F:4:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [46399:5:0x0006]: initializing channel: from_cache: False [46399:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [46399:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [46399:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [46399:5:0x0006]: Reading attributes in chunks: ['on_off'] [0xB53F:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=85, command_id=, *is_reply=False) [0xB53F:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0xB53F:1:0x0006] Received ZCL frame: b'\x18M\x01\x00\x00\x00\x10\x01' [0xB53F:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=77, command_id=1, *is_reply=True) [0xB53F:1:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [46399:1:0x0006]: finished channel initialization [46399:1:0x0006]: 'async_initialize' stage succeeded [46399:1:0x0003]: 'async_initialize' stage succeeded [46399:1:0x0000]: 'async_initialize' stage succeeded [46399:1:0x0019]: 'async_initialize' stage succeeded [0xB53F:2:0x0006] Received ZCL frame: b'\x18O\x01\x00\x00\x00\x10\x01' [0xB53F:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=79, command_id=1, *is_reply=True) [0xB53F:2:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [46399:2:0x0006]: finished channel initialization [46399:2:0x0006]: 'async_initialize' stage succeeded [0xB53F:3:0x0006] Received ZCL frame: b'\x18Q\x01\x00\x00\x00\x10\x01' [0xB53F:3:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=81, command_id=1, *is_reply=True) [0xB53F:3:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [46399:3:0x0006]: finished channel initialization [46399:3:0x0006]: 'async_initialize' stage succeeded [0xB53F:4:0x0006] Received ZCL frame: b'\x18S\x01\x00\x00\x00\x10\x01' [0xB53F:4:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=83, command_id=1, *is_reply=True) [0xB53F:4:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [46399:4:0x0006]: finished channel initialization [46399:4:0x0006]: 'async_initialize' stage succeeded [0xB53F:5:0x0006] Received ZCL frame: b'\x18U\x01\x00\x00\x00\x10\x01' [0xB53F:5:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=85, command_id=1, *is_reply=True) [0xB53F:5:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=, value=TypeValue(type=Bool, value=))]) [46399:5:0x0006]: finished channel initialization [46399:5:0x0006]: 'async_initialize' stage succeeded [46399](TS011F): power source: Mains [46399](TS011F): completed initialization [0xb53f:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0xb53f:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0xb53f:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0xb53f:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0xb53f:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0xb53f:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) [0xb53f:zdo] ZDO request ZDOCmd.Bind_rsp: [] [0xb53f:zdo] No handler for ZDO request:ZDOCmd.Bind_rsp([]) [0xb53f:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000] [0xb53f:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000]) Device 0x5eeb (a4:c1:38:84:36:44:41:d7) joined the network Device a4:c1:38:84:36:44:41:d7 changed id (0x5eeb => 0x5eeb) [0x5eeb] Skipping initialization, device is fully initialized Device is initialized Checking quirks for _TZ3000_cfnprab5 TS011F (a4:c1:38:84:36:44:41:d7) Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because input cluster mismatch on at least one endpoint Considering Fail because endpoint list mismatch: {242, 1, 2, 3} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {242, 11} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 2, 242} {1, 2, 3, 4, 5, 242} Considering Fail because input cluster mismatch on at least one endpoint Considering Fail because endpoint list mismatch: {242, 1, 2, 3} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {242, 11} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1, 242} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {232, 230} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {11, 13} {1, 2, 3, 4, 5, 242} Considering Fail because endpoint list mismatch: {1} {1, 2, 3, 4, 5, 242} [0x5eeb:zdo] ZDO request ZDOCmd.Device_annce: [0x5EEB, a4:c1:38:84:36:44:41:d7, 142] device - 24299:a4:c1:38:84:36:44:41:d7 entering async_device_initialized - is_new_join: False device - 24299:a4:c1:38:84:36:44:41:d7 has been reset and re-added or its nwk address changed skipping discovery for previously discovered device - 24299:a4:c1:38:84:36:44:41:d7 [24299](TS011F): started configuration [24299:ZDO](TS011F): 'async_configure' stage succeeded [24299:1:0x0006]: Performing cluster binding [24299:1:0x0003]: Configuring cluster attribute reporting [24299:1:0x0003]: finished channel configuration [24299:1:0x0000]: Configuring cluster attribute reporting [24299:1:0x0000]: finished channel configuration [24299:1:0x0019]: finished channel configuration [24299:2:0x0006]: Performing cluster binding [24299:3:0x0006]: Performing cluster binding [24299:4:0x0006]: Performing cluster binding [24299:5:0x0006]: Performing cluster binding [0x5eeb] Delivery error for seq # 0x5b, on endpoint id 0 cluster 0x0021: message send failure [24299:3:0x0006]: Failed to bind 'on_off' cluster: [0x5eeb:0:0x0021]: Message send failure [24299:3:0x0006]: Configuring cluster attribute reporting [0x5EEB:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=97, command_id=, *is_reply=False) [0x5EEB:3:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x5eeb] Delivery error for seq # 0x5d, on endpoint id 0 cluster 0x0021: message send failure [24299:4:0x0006]: Failed to bind 'on_off' cluster: [0x5eeb:0:0x0021]: Message send failure [24299:4:0x0006]: Configuring cluster attribute reporting [0x5EEB:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=99, command_id=, *is_reply=False) [0x5EEB:4:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x5eeb] Delivery error for seq # 0x5f, on endpoint id 0 cluster 0x0021: message send failure [24299:5:0x0006]: Failed to bind 'on_off' cluster: [0x5eeb:0:0x0021]: Message send failure [24299:5:0x0006]: Configuring cluster attribute reporting [0x5EEB:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=101, command_id=, *is_reply=False) [0x5EEB:5:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x5eeb] Delivery error for seq # 0x61, on endpoint id 3 cluster 0x0006: message send failure [24299:3:0x0006]: failed to set reporting on 'on_off' cluster for: [0x5eeb:3:0x0006]: Message send failure [24299:3:0x0006]: finished channel configuration [24299:3:0x0006]: 'async_configure' stage succeeded [0x5eeb] Delivery error for seq # 0x63, on endpoint id 4 cluster 0x0006: message send failure [24299:4:0x0006]: failed to set reporting on 'on_off' cluster for: [0x5eeb:4:0x0006]: Message send failure [24299:4:0x0006]: finished channel configuration [24299:4:0x0006]: 'async_configure' stage succeeded [24299:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS [24299:1:0x0006]: Configuring cluster attribute reporting [0x5EEB:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=103, command_id=, *is_reply=False) [0x5EEB:1:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x5eeb] Delivery error for seq # 0x65, on endpoint id 5 cluster 0x0006: message send failure [24299:5:0x0006]: failed to set reporting on 'on_off' cluster for: [0x5eeb:5:0x0006]: Message send failure [24299:5:0x0006]: finished channel configuration [24299:5:0x0006]: 'async_configure' stage succeeded [24299:2:0x0006]: bound 'on_off' cluster: Status.SUCCESS [24299:2:0x0006]: Configuring cluster attribute reporting [0x5EEB:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=105, command_id=, *is_reply=False) [0x5EEB:2:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)]) [0x5eeb:zdo] ZDO request ZDOCmd.Bind_rsp: [] [0x5eeb:zdo] No handler for ZDO request:ZDOCmd.Bind_rsp([]) [0x5eeb:zdo] ZDO request ZDOCmd.Bind_rsp: [] [0x5eeb:zdo] No handler for ZDO request:ZDOCmd.Bind_rsp([]) Device 0x5eeb (a4:c1:38:84:36:44:41:d7) joined the network [0x5eeb:zdo] ZDO request ZDOCmd.Device_annce: [0x5EEB, a4:c1:38:84:36:44:41:d7, 142] [0x5EEB:1:0x0004] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=107, command_id=2, *is_reply=False) [0x5EEB:1:0x0004] Sending request: get_membership(groups=[]) [0x5EEB:1:0x0004] Received ZCL frame: b'\x19k\x02 \x00' [0x5EEB:1:0x0004] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=107, command_id=2, *is_reply=True) [0x5EEB:1:0x0004] Decoded ZCL frame: Groups:get_membership_response(capacity=32, groups=[]) [0x5EEB:2:0x0004] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=109, command_id=2, *is_reply=False) [0x5EEB:2:0x0004] Sending request: get_membership(groups=[]) [0x5EEB:1:0x0004] Received ZCL frame: b'\x18k\x0b\x02\x00' [0x5EEB:1:0x0004] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=107, command_id=11, *is_reply=True) [0x5EEB:1:0x0004] Decoded ZCL frame: Groups:Default_Response(command_id=2, status=) [0x5EEB:1:0x0004] Received command 0x0B (TSN 107): Default_Response(command_id=2, status=) [0x5EEB:2:0x0004] Received ZCL frame: b'\x19m\x02 \x00' [0x5EEB:2:0x0004] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=109, command_id=2, *is_reply=True) [0x5EEB:2:0x0004] Decoded ZCL frame: Groups:get_membership_response(capacity=32, groups=[]) [0x5EEB:3:0x0004] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=111, command_id=2, *is_reply=False) [0x5EEB:3:0x0004] Sending request: get_membership(groups=[]) [0x5EEB:2:0x0004] Received ZCL frame: b'\x18m\x0b\x02\x00' [0x5EEB:2:0x0004] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=0, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=109, command_id=11, *is_reply=True) [0x5EEB:2:0x0004] Decoded ZCL frame: Groups:Default_Response(command_id=2, status=) [0x5EEB:2:0x0004] Received command 0x0B (TSN 109): Default_Response(command_id=2, status=) [24299:1:0x0006]: failed to set reporting on 'on_off' cluster for: [24299:1:0x0006]: finished channel configuration [24299:1:0x0006]: 'async_configure' stage succeeded [24299:1:0x0003]: 'async_configure' stage succeeded [24299:1:0x0000]: 'async_configure' stage succeeded [24299:1:0x0019]: 'async_configure' stage succeeded [24299:2:0x0006]: failed to set reporting on 'on_off' cluster for: [24299:2:0x0006]: finished channel configuration [24299:2:0x0006]: 'async_configure' stage succeeded [24299](TS011F): completed configuration [24299](TS011F): stored in registry: ZhaDeviceEntry(name='_TZ3000_cfnprab5 TS011F', ieee='a4:c1:38:84:36:44:41:d7', last_seen=1656094402.997513) [0x5EEB:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=113, command_id=64, *is_reply=False) [0x5EEB:1:0x0003] Sending request: trigger_effect(effect_id=, effect_variant=) [0x5eeb] Delivery error for seq # 0x71, on endpoint id 1 cluster 0x0003: message send failure [24299:1:0x0003]: command failed: 'trigger_effect' args: '(2, 0)' kwargs '{}' exception: '[0x5eeb:1:0x0003]: Message send failure' [24299](TS011F): Update device availability - device available: False - new availability: True - changed: True [24299](TS011F): Device availability changed and device became available, reinitializing channels [24299](TS011F): started initialization [24299:ZDO](TS011F): 'async_initialize' stage succeeded [24299:1:0x0006]: initializing channel: from_cache: False [24299:1:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:1:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:1:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:1:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=115, command_id=, *is_reply=False) [0x5EEB:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [24299:1:0x0003]: initializing channel: from_cache: False [24299:1:0x0003]: finished channel initialization [24299:1:0x0000]: initializing channel: from_cache: False [24299:1:0x0000]: finished channel initialization [24299:1:0x0019]: initializing channel: from_cache: False [24299:1:0x0019]: finished channel initialization [24299:2:0x0006]: initializing channel: from_cache: False [24299:2:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:2:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:2:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:2:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=117, command_id=, *is_reply=False) [0x5EEB:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [24299:3:0x0006]: initializing channel: from_cache: False [24299:3:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:3:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:3:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:3:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=119, command_id=, *is_reply=False) [0x5EEB:3:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [24299:4:0x0006]: initializing channel: from_cache: False [24299:4:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:4:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:4:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:4:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=121, command_id=, *is_reply=False) [0x5EEB:4:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [24299:5:0x0006]: initializing channel: from_cache: False [24299:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:5:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=123, command_id=, *is_reply=False) [0x5EEB:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x73, on endpoint id 1 cluster 0x0006: message send failure [24299:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:1:0x0006]: Message send failure [24299:1:0x0006]: async_initialize: retryable request #1 failed: [0x5eeb:1:0x0006]: Message send failure. Retrying in 0.9s [0x5eeb] Delivery error for seq # 0x75, on endpoint id 2 cluster 0x0006: message send failure [24299:2:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:2:0x0006]: Message send failure [24299:2:0x0006]: async_initialize: retryable request #1 failed: [0x5eeb:2:0x0006]: Message send failure. Retrying in 1.1s [0x5eeb] Delivery error for seq # 0x77, on endpoint id 3 cluster 0x0006: message send failure [24299:3:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:3:0x0006]: Message send failure [24299:3:0x0006]: async_initialize: retryable request #1 failed: [0x5eeb:3:0x0006]: Message send failure. Retrying in 0.9s [0x5eeb] Delivery error for seq # 0x79, on endpoint id 4 cluster 0x0006: message send failure [24299:4:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:4:0x0006]: Message send failure [24299:4:0x0006]: async_initialize: retryable request #1 failed: [0x5eeb:4:0x0006]: Message send failure. Retrying in 1.1s [0x5eeb] Delivery error for seq # 0x7b, on endpoint id 5 cluster 0x0006: message send failure [24299:5:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:5:0x0006]: Message send failure [24299:5:0x0006]: async_initialize: retryable request #1 failed: [0x5eeb:5:0x0006]: Message send failure. Retrying in 1.2s [24299:1:0x0006]: initializing channel: from_cache: False [24299:1:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:1:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:1:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:1:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=125, command_id=, *is_reply=False) [0x5EEB:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x7d, on endpoint id 1 cluster 0x0006: message send failure [24299:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:1:0x0006]: Message send failure [24299:1:0x0006]: async_initialize: retryable request #2 failed: [0x5eeb:1:0x0006]: Message send failure. Retrying in 1.0s [24299:3:0x0006]: initializing channel: from_cache: False [24299:3:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:3:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:3:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:3:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=127, command_id=, *is_reply=False) [0x5EEB:3:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x7f, on endpoint id 3 cluster 0x0006: message send failure [24299:3:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:3:0x0006]: Message send failure [24299:3:0x0006]: async_initialize: retryable request #2 failed: [0x5eeb:3:0x0006]: Message send failure. Retrying in 1.2s [24299:2:0x0006]: initializing channel: from_cache: False [24299:2:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:2:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:2:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:2:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=129, command_id=, *is_reply=False) [0x5EEB:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x81, on endpoint id 2 cluster 0x0006: message send failure [24299:2:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:2:0x0006]: Message send failure [24299:2:0x0006]: async_initialize: retryable request #2 failed: [0x5eeb:2:0x0006]: Message send failure. Retrying in 0.8s [24299:4:0x0006]: initializing channel: from_cache: False [24299:4:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:4:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:4:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:4:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=131, command_id=, *is_reply=False) [0x5EEB:4:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x83, on endpoint id 4 cluster 0x0006: message send failure [24299:4:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:4:0x0006]: Message send failure [24299:4:0x0006]: async_initialize: retryable request #2 failed: [0x5eeb:4:0x0006]: Message send failure. Retrying in 1.2s [24299:5:0x0006]: initializing channel: from_cache: False [24299:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:5:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=133, command_id=, *is_reply=False) [0x5EEB:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x85, on endpoint id 5 cluster 0x0006: message send failure [24299:5:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:5:0x0006]: Message send failure [24299:5:0x0006]: async_initialize: retryable request #2 failed: [0x5eeb:5:0x0006]: Message send failure. Retrying in 0.9s [24299:1:0x0006]: initializing channel: from_cache: False [24299:1:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:1:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:1:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:1:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=135, command_id=, *is_reply=False) [0x5EEB:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x87, on endpoint id 1 cluster 0x0006: message send failure [24299:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:1:0x0006]: Message send failure [24299:1:0x0006]: async_initialize: retryable request #3 failed: [0x5eeb:1:0x0006]: Message send failure. Retrying in 2.6s [24299:2:0x0006]: initializing channel: from_cache: False [24299:2:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:2:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:2:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:2:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=137, command_id=, *is_reply=False) [0x5EEB:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x89, on endpoint id 2 cluster 0x0006: message send failure [24299:2:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:2:0x0006]: Message send failure [24299:2:0x0006]: async_initialize: retryable request #3 failed: [0x5eeb:2:0x0006]: Message send failure. Retrying in 2.9s [24299:3:0x0006]: initializing channel: from_cache: False [24299:3:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:3:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:3:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:3:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=139, command_id=, *is_reply=False) [0x5EEB:3:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x8b, on endpoint id 3 cluster 0x0006: message send failure [24299:3:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:3:0x0006]: Message send failure [24299:3:0x0006]: async_initialize: retryable request #3 failed: [0x5eeb:3:0x0006]: Message send failure. Retrying in 3.0s [24299:5:0x0006]: initializing channel: from_cache: False [24299:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:5:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=141, command_id=, *is_reply=False) [0x5EEB:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x8d, on endpoint id 5 cluster 0x0006: message send failure [24299:5:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:5:0x0006]: Message send failure [24299:5:0x0006]: async_initialize: retryable request #3 failed: [0x5eeb:5:0x0006]: Message send failure. Retrying in 3.6s [24299:4:0x0006]: initializing channel: from_cache: False [24299:4:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:4:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:4:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:4:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=143, command_id=, *is_reply=False) [0x5EEB:4:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x8f, on endpoint id 4 cluster 0x0006: message send failure [24299:4:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:4:0x0006]: Message send failure [24299:4:0x0006]: async_initialize: retryable request #3 failed: [0x5eeb:4:0x0006]: Message send failure. Retrying in 3.3s [0x5eeb:3] Failed to sync-up group membership [0x5EEB:4:0x0004] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=145, command_id=2, *is_reply=False) [0x5EEB:4:0x0004] Sending request: get_membership(groups=[]) [0x5eeb] Delivery error for seq # 0x91, on endpoint id 4 cluster 0x0004: message send failure [0x5eeb:4] Failed to sync-up group membership [0x5EEB:5:0x0004] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=147, command_id=2, *is_reply=False) [0x5EEB:5:0x0004] Sending request: get_membership(groups=[]) [0x5eeb] Delivery error for seq # 0x93, on endpoint id 5 cluster 0x0004: message send failure [0x5eeb:5] Failed to sync-up group membership [24299:1:0x0006]: initializing channel: from_cache: False [24299:1:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:1:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:1:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:1:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=149, command_id=, *is_reply=False) [0x5EEB:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [24299:2:0x0006]: initializing channel: from_cache: False [24299:2:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:2:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:2:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:2:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=151, command_id=, *is_reply=False) [0x5EEB:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x97, on endpoint id 2 cluster 0x0006: message send failure [24299:2:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:2:0x0006]: Message send failure [24299:2:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0x5eeb:2:0x0006]: Message send failure'), DeliveryError('[0x5eeb:2:0x0006]: Message send failure'), DeliveryError('[0x5eeb:2:0x0006]: Message send failure'), DeliveryError('[0x5eeb:2:0x0006]: Message send failure')] [24299:2:0x0006]: 'async_initialize' stage succeeded [24299:3:0x0006]: initializing channel: from_cache: False [24299:3:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:3:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:3:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:3:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:3:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=153, command_id=, *is_reply=False) [0x5EEB:3:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x99, on endpoint id 3 cluster 0x0006: message send failure [24299:3:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:3:0x0006]: Message send failure [24299:3:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0x5eeb:3:0x0006]: Message send failure'), DeliveryError('[0x5eeb:3:0x0006]: Message send failure'), DeliveryError('[0x5eeb:3:0x0006]: Message send failure'), DeliveryError('[0x5eeb:3:0x0006]: Message send failure')] [24299:3:0x0006]: 'async_initialize' stage succeeded [24299:4:0x0006]: initializing channel: from_cache: False [24299:4:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:4:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:4:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:4:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:4:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=155, command_id=, *is_reply=False) [0x5EEB:4:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x9b, on endpoint id 4 cluster 0x0006: message send failure [24299:4:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:4:0x0006]: Message send failure [24299:4:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0x5eeb:4:0x0006]: Message send failure'), DeliveryError('[0x5eeb:4:0x0006]: Message send failure'), DeliveryError('[0x5eeb:4:0x0006]: Message send failure'), DeliveryError('[0x5eeb:4:0x0006]: Message send failure')] [24299:4:0x0006]: 'async_initialize' stage succeeded [24299:5:0x0006]: initializing channel: from_cache: False [24299:5:0x0006]: initializing cached channel attributes: ['start_up_on_off'] [24299:5:0x0006]: Reading attributes in chunks: ['start_up_on_off'] [24299:5:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False] [24299:5:0x0006]: Reading attributes in chunks: ['on_off'] [0x5EEB:5:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=, is_manufacturer_specific=False, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=157, command_id=, *is_reply=False) [0x5EEB:5:0x0006] Sending request: Read_Attributes(attribute_ids=[0]) [0x5eeb] Delivery error for seq # 0x9d, on endpoint id 5 cluster 0x0006: message send failure [24299:5:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:5:0x0006]: Message send failure [24299:5:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0x5eeb:5:0x0006]: Message send failure'), DeliveryError('[0x5eeb:5:0x0006]: Message send failure'), DeliveryError('[0x5eeb:5:0x0006]: Message send failure'), DeliveryError('[0x5eeb:5:0x0006]: Message send failure')] [24299:5:0x0006]: 'async_initialize' stage succeeded [0x5eeb] Delivery error for seq # 0x95, on endpoint id 1 cluster 0x0006: message send failure [24299:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0x5eeb:1:0x0006]: Message send failure [24299:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0x5eeb:1:0x0006]: Message send failure'), DeliveryError('[0x5eeb:1:0x0006]: Message send failure'), DeliveryError('[0x5eeb:1:0x0006]: Message send failure'), DeliveryError('[0x5eeb:1:0x0006]: Message send failure')] [24299:1:0x0006]: 'async_initialize' stage succeeded [24299:1:0x0003]: 'async_initialize' stage succeeded [24299:1:0x0000]: 'async_initialize' stage succeeded [24299:1:0x0019]: 'async_initialize' stage succeeded [24299](TS011F): power source: Mains [24299](TS011F): completed initialization [0x0000](ConBee II): Device seen - marking the device available and resetting counter [0x0000](ConBee II): Update device availability - device available: True - new availability: True - changed: False [24299](TS011F): Device seen - marking the device available and resetting counter [24299](TS011F): Update device availability - device available: True - new availability: True - changed: False [0xE612](lumi.sensor_magnet.aq2): Device seen - marking the device available and resetting counter [0xE612](lumi.sensor_magnet.aq2): Update device availability - device available: True - new availability: True - changed: False