Ikea Motion sensor, no history

Hi

I am running HA on a debian PC using docker compose with imag 2022:11

ZHA is installed, using Sonoff USB3 with latest firmware.

Using ZHA I added a IKEA Motion sensor.

During the install process, ZHA and IKEA nothing indicated any problems.

Skärmbild 2022-11-26 115400

My problems seems to be that I never gets any events from the motion sensor. Looking at the history it does not show any changes what so ever.

I fully understand that based on the information in this thread it will be hard to tell me whats wrong. I hoping for some debugging advice to pinpoint the problem.
I’ve seen Youtube videos where the author not having any problems setting this up, so something must be off in my setup.
How to find it?

Some more information. This is from logfile, when I added the motion sensors.
A lot of failures in the log but HA tells me it went wll.

Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=3, profile_id=0, cluster_id=32822, data=Serialized[b'\x03\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
[0x0000:zdo] ZDO request ZDOCmd.Mgmt_Permit_Joining_rsp: [<Status.SUCCESS: 0>]
[0x0000:zdo] No handler for ZDO request:ZDOCmd.Mgmt_Permit_Joining_rsp([<Status.SUCCESS: 0>])
Sending 'zdo_leave_req' failed: 
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=129, profile_id=0, cluster_id=19, data=Serialized[b'\x81!r\xdf\xfdB\xfe\xffW\xb4\x14\x80'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
New device 0x7221 (14:b4:57:ff:fe:42:fd:df) joined the network
[0x7221] Scheduling initialization
Received frame on uninitialized device <Device model=None manuf=None nwk=0x7221 ieee=14:b4:57:ff:fe:42:fd:df is_initialized=False> from ep 0 to ep 0, cluster 19: b'\x81!r\xdf\xfdB\xfe\xffW\xb4\x14\x80'
[0x7221:zdo] ZDO request ZDOCmd.Device_annce: [0x7221, 14:b4:57:ff:fe:42:fd:df, 128]
Tries remaining: 3
[0x7221] Requesting 'Node Descriptor'
Tries remaining: 2
[0x7221] Extending timeout for 0x13 request
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=19, profile_id=0, cluster_id=32770, data=Serialized[b'\x13\x00!r\x02@\x80|\x11RR\x00\x00,R\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
Received frame on uninitialized device <Device model=None manuf=None nwk=0x7221 ieee=14:b4:57:ff:fe:42:fd:df is_initialized=False> from ep 0 to ep 0, cluster 32770: b'\x13\x00!r\x02@\x80|\x11RR\x00\x00,R\x00\x00'
[0x7221] Got Node Descriptor: NodeDescriptor(logical_type=<LogicalType.EndDevice: 2>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.AllocateAddress: 128>, manufacturer_code=4476, maximum_buffer_size=82, maximum_incoming_transfer_size=82, server_mask=11264, maximum_outgoing_transfer_size=82, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=False, *is_coordinator=False, *is_end_device=True, *is_full_function_device=False, *is_mains_powered=False, *is_receiver_on_when_idle=False, *is_router=False, *is_security_capable=False)
[0x7221] Discovering endpoints
Tries remaining: 3
[0x7221] Extending timeout for 0x14 request
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=20, profile_id=0, cluster_id=32773, data=Serialized[b'\x14\x00!r\x01\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
Received frame on uninitialized device <Device model=None manuf=None nwk=0x7221 ieee=14:b4:57:ff:fe:42:fd:df is_initialized=False> from ep 0 to ep 0, cluster 32773: b'\x14\x00!r\x01\x01'
[0x7221] Discovered endpoints: [1]
[0x7221] Initializing endpoints [<Endpoint id=1 in=[] out=[] status=<Status.NEW: 0>>]
[0x7221:1] Discovering endpoint information
Tries remaining: 3
[0x7221] Extending timeout for 0x15 request
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=21, profile_id=0, cluster_id=32772, data=Serialized[b'\x15\x00!r"\x01\x04\x01P\x08\x01\x07\x00\x00\x01\x00\x03\x00\t\x00 \x00\x00\x10|\xfc\x06\x03\x00\x04\x00\x06\x00\x08\x00\x19\x00\x00\x10'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
Received frame on uninitialized device <Device model=None manuf=None nwk=0x7221 ieee=14:b4:57:ff:fe:42:fd:df is_initialized=False> from ep 0 to ep 0, cluster 32772: b'\x15\x00!r"\x01\x04\x01P\x08\x01\x07\x00\x00\x01\x00\x03\x00\t\x00 \x00\x00\x10|\xfc\x06\x03\x00\x04\x00\x06\x00\x08\x00\x19\x00\x00\x10'
[0x7221:1] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=1, profile=260, device_type=2128, device_version=1, input_clusters=[0, 1, 3, 9, 32, 4096, 64636], output_clusters=[3, 4, 6, 8, 25, 4096])
[0x7221:1:0x0000] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True, *is_reply=False), tsn=22, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>, *is_reply=False)
[0x7221:1:0x0000] Sending request: Read_Attributes(attribute_ids=[4, 5])
[0x7221] Extending timeout for 0x16 request
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=0, data=Serialized[b'\x18\x16\x01\x04\x00\x00B\x0eIKEA of Sweden\x05\x00\x00B\x15TRADFRI motion sensor'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=178, rssi=None)
[0x7221:1:0x0000] Received ZCL frame: b'\x18\x16\x01\x04\x00\x00B\x0eIKEA of Sweden\x05\x00\x00B\x15TRADFRI motion sensor'
[0x7221:1:0x0000] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=22, command_id=1, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
[0x7221:1:0x0000] Decoded ZCL frame: Basic:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0004, status=<Status.SUCCESS: 0>, value=TypeValue(type=CharacterString, value='IKEA of Sweden')), ReadAttributeRecord(attrid=0x0005, status=<Status.SUCCESS: 0>, value=TypeValue(type=CharacterString, value='TRADFRI motion sensor'))])
[0x7221] Read model 'TRADFRI motion sensor' and manufacturer 'IKEA of Sweden' from <Endpoint id=1 in=[basic:0x0000, power:0x0001, identify:0x0003, alarms:0x0009, poll_control:0x0020, lightlink:0x1000, manufacturer_specific:0xFC7C] out=[identify:0x0003, groups:0x0004, on_off:0x0006, level:0x0008, ota:0x0019, lightlink:0x1000] status=<Status.ZDO_INIT: 1>>
[0x7221] Discovered basic device information for <Device model='TRADFRI motion sensor' manuf='IKEA of Sweden' nwk=0x7221 ieee=14:b4:57:ff:fe:42:fd:df is_initialized=True>
Device is initialized <Device model='TRADFRI motion sensor' manuf='IKEA of Sweden' nwk=0x7221 ieee=14:b4:57:ff:fe:42:fd:df is_initialized=True>
Checking quirks for IKEA of Sweden TRADFRI motion sensor (14:b4:57:ff:fe:42:fd:df)
Considering <class 'zhaquirks.ikea.motionzha.IkeaTradfriMotionE1745'>
Found custom device replacement for 14:b4:57:ff:fe:42:fd:df: <class 'zhaquirks.ikea.motionzha.IkeaTradfriMotionE1745'>
'button' component -> 'ZHAIdentifyButton' using ['identify']
'sensor' component -> 'Battery' using ['power']
'sensor' component -> 'RSSISensor' using ['basic']
'sensor' component -> 'LQISensor' using ['basic']
device - 0x7221:14:b4:57:ff:fe:42:fd:df entering async_device_initialized - is_new_join: True
device - 0x7221:14:b4:57:ff:fe:42:fd:df has joined the ZHA zigbee network
[0x7221](TRADFRI motion sensor): started configuration
[0x7221:ZDO](TRADFRI motion sensor): 'async_configure' stage succeeded
[0x7221:1:0x0003]: Configuring cluster attribute reporting
Error handling '_save_attribute' event with (14:b4:57:ff:fe:42:fd:df, 1, 0, 4, 'IKEA of Sweden') params: FOREIGN KEY constraint failed
Error handling '_save_attribute' event with (14:b4:57:ff:fe:42:fd:df, 1, 0, 5, 'TRADFRI motion sensor') params: FOREIGN KEY constraint failed
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=4096, data=Serialized[b'\x19\x18A\x01\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=178, rssi=None)
[0x7221:1:0x1000] Received ZCL frame: b'\x19\x18A\x01\x00\x00'
[0x7221:1:0x1000] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False, *is_reply=True), tsn=24, command_id=65, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
[0x7221:1:0x1000] Decoded ZCL frame: LightLinkCluster:get_group_identifiers_rsp(total=1, start_index=0, group_info_records=[])
[0x0000:2] Cannot add 0x0000 group, no groups cluster
[0x0000:1] Cannot add 0x0000 group, no groups cluster
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=23, profile_id=0, cluster_id=32801, data=Serialized[b'\x17\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
[0x7221:1:0x0001]: bound 'power' cluster: Status.SUCCESS
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=1, data=Serialized[b'\x08\x1d\x07\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=178, rssi=None)
[0x7221:1:0x0001] Received ZCL frame: b'\x08\x1d\x07\x00'
[0x7221:1:0x0001] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=29, command_id=7, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
[0x7221:1:0x0001] Decoded ZCL frame: PowerConfiguration2CRCluster:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=<Status.SUCCESS: 0>)])
[0x7221:1:0x0001]: Successfully configured reporting for '{'battery_voltage': (3600, 10800, 1), 'battery_percentage_remaining': (3600, 10800, 1)}' on 'power' cluster: [ConfigureReportingResponseRecord(status=<Status.SUCCESS: 0>)]
[0x7221:1:0x0020]: Failed to bind 'poll_control' cluster: 
[0x7221:1:0x0006]: Failed to bind 'on_off' cluster: 
[0x7221:1:0x0008]: Failed to bind 'level' cluster: 
[0x7221:1:0x0006]: Failed to bind 'on_off' cluster: 
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=6, data=Serialized[b'\x01\x02B\x00\x08\x07\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=11, non_member_radius=0, lqi=189, rssi=None)
[0x7221:1:0x0006] Received ZCL frame: b'\x01\x02B\x00\x08\x07\x00\x00'
[0x7221:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False, *is_reply=False), tsn=2, command_id=66, *direction=<Direction.Server_to_Client: 0>, *is_reply=False)
[0x7221:1:0x0006] Decoded ZCL frame: OnOff:on_with_timed_off(on_off_control=<OnOffControl.0: 0>, on_time=1800, off_wait_time=0)
[0x7221:1:0x0006] Received command 0x42 (TSN 2): on_with_timed_off(on_off_control=<OnOffControl.0: 0>, on_time=1800, off_wait_time=0)
[0x7221:1:0x0006] No explicit handler for cluster command 0x42: on_with_timed_off(on_off_control=<OnOffControl.0: 0>, on_time=1800, off_wait_time=0)
[0x7221:1:0x0006]: received 'on_with_timed_off' command with on_with_timed_off(on_off_control=<OnOffControl.0: 0>, on_time=1800, off_wait_time=0) args on cluster_id '6' tsn '2'
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=32, data=Serialized[b'\x18\x1e\x04\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=189, rssi=None)
[0x7221:1:0x0020] Received ZCL frame: b'\x18\x1e\x04\x00'
[0x7221:1:0x0020] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=30, command_id=4, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
[0x7221:1:0x0020] Decoded ZCL frame: PollControl:Write_Attributes_rsp(status_records=[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)])
[0x7221:1:0x0020]: 3300.0s check-in interval set: Write_Attributes_rsp(status_records=[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)])
[0x7221:1:0x0020]: finished channel configuration
[0x7221:1:0x0003]: 'async_configure' stage succeeded
[0x7221:1:0x0000]: 'async_configure' stage succeeded
[0x7221:1:0x0001]: 'async_configure' stage succeeded
[0x7221:1:0x1000]: 'async_configure' stage succeeded
[0x7221:1:0x0020]: 'async_configure' stage succeeded
[0x7221:1:0x0006]: 'async_configure' stage succeeded
[0x7221:1:0x0008]: 'async_configure' stage succeeded
[0x7221:1:0x0006]: 'async_configure' stage succeeded
[0x7221:1:0x0019]: 'async_configure' stage succeeded
[0x7221](TRADFRI motion sensor): completed configuration
[0x7221:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False, *is_reply=False), tsn=31, command_id=64, *direction=<Direction.Server_to_Client: 0>, *is_reply=False)
[0x7221:1:0x0003] Sending request: trigger_effect(effect_id=<EffectIdentifier.Okay: 2>, effect_variant=<EffectVariant.Default: 0>)
[0x7221] Extending timeout for 0x1f request
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=3, data=Serialized[b'\x08\x1f\x0b@\x81'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=189, rssi=None)
[0x7221:1:0x0003] Received ZCL frame: b'\x08\x1f\x0b@\x81'
[0x7221:1:0x0003] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=31, command_id=11, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
[0x7221:1:0x0003] Decoded ZCL frame: Identify:Default_Response(command_id=64, status=<Status.UNSUP_CLUSTER_COMMAND: 129>)
[0x7221:1:0x0003]: executed 'trigger_effect' command with args: '()' kwargs: '{'effect_id': <EffectIdentifier.Okay: 2>, 'effect_variant': <EffectVariant.Default: 0>}' result: Default_Response(command_id=64, status=<Status.UNSUP_CLUSTER_COMMAND: 129>)
[0x7221](TRADFRI motion sensor): started initialization
[0x7221:ZDO](TRADFRI motion sensor): 'async_initialize' stage succeeded
[0x7221:1:0x0003]: initializing channel: from_cache: False
[0x7221:1:0x0003]: finished channel initialization
[0x7221:1:0x0000]: initializing channel: from_cache: False
[0x7221:1:0x0000]: finished channel initialization
[0x7221:1:0x0001]: initializing channel: from_cache: False
[0x7221:1:0x0001]: initializing uncached channel attributes: ['battery_voltage', 'battery_percentage_remaining'] - from cache[False]
[0x7221:1:0x0001]: Reading attributes in chunks: ['battery_voltage', 'battery_percentage_remaining']
[0x7221:1:0x0001] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True, *is_reply=False), tsn=32, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>, *is_reply=False)
[0x7221:1:0x0001] Sending request: Read_Attributes(attribute_ids=[32, 33])
[0x7221] Extending timeout for 0x20 request
[0x7221:1:0x1000]: initializing channel: from_cache: False
[0x7221:1:0x1000]: finished channel initialization
[0x7221:1:0x0020]: initializing channel: from_cache: False
[0x7221:1:0x0020]: finished channel initialization
[0x7221:1:0x0006]: initializing channel: from_cache: False
[0x7221:1:0x0006]: initializing cached channel attributes: ['start_up_on_off']
[0x7221:1:0x0006]: Reading attributes in chunks: ['start_up_on_off']
[0x7221:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=33, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
[0x7221:1:0x0006] Sending request: Read_Attributes(attribute_ids=[16387])
[0x7221] Extending timeout for 0x21 request
[0x7221:1:0x0008]: initializing channel: from_cache: False
[0x7221:1:0x0008]: finished channel initialization
[0x7221:1:0x0006]: initializing channel: from_cache: False
[0x7221:1:0x0006]: finished channel initialization
[0x7221:1:0x0019]: initializing channel: from_cache: False
[0x7221:1:0x0019]: finished channel initialization
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=1, data=Serialized[b'\x18 \x01 \x00\x00 \x1b!\x00\x00 /'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=189, rssi=None)
[0x7221:1:0x0001] Received ZCL frame: b'\x18 \x01 \x00\x00 \x1b!\x00\x00 /'
[0x7221:1:0x0001] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=32, command_id=1, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
[0x7221:1:0x0001] Decoded ZCL frame: PowerConfiguration2CRCluster:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0020, status=<Status.SUCCESS: 0>, value=TypeValue(type=uint8_t, value=27)), ReadAttributeRecord(attrid=0x0021, status=<Status.SUCCESS: 0>, value=TypeValue(type=uint8_t, value=47))])
[0x7221:1:0x0001]: Performing channel specific initialization: ['battery_voltage', 'battery_percentage_remaining']
[0x7221:1:0x0001]: Reading attributes in chunks: ['battery_size', 'battery_quantity']
[0x7221:1:0x0001]: finished channel initialization
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=6, data=Serialized[b'\x10!\x01\x03@\x86'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=193, rssi=None)
[0x7221:1:0x0006] Received ZCL frame: b'\x10!\x01\x03@\x86'
[0x7221:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 0>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=False), tsn=33, command_id=1, *direction=<Direction.Server_to_Client: 0>, *is_reply=False)
[0x7221:1:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x4003, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>)])
[0x7221:1:0x0006]: initializing uncached channel attributes: ['on_off'] - from cache[False]
[0x7221:1:0x0006]: Reading attributes in chunks: ['on_off']
[0x7221:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=True), tsn=34, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Client_to_Server: 1>, *is_reply=True)
[0x7221:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0])
[0x7221] Extending timeout for 0x22 request
Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7221), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=6, data=Serialized[b'\x10"\x01\x00\x00\x86'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=189, rssi=None)
[0x7221:1:0x0006] Received ZCL frame: b'\x10"\x01\x00\x00\x86'
[0x7221:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 0>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True, *is_reply=False), tsn=34, command_id=1, *direction=<Direction.Server_to_Client: 0>, *is_reply=False)
[0x7221:1:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>)])
[0x7221:1:0x0006]: finished channel initialization
[0x7221:1:0x0003]: 'async_initialize' stage succeeded
[0x7221:1:0x0000]: 'async_initialize' stage succeeded
[0x7221:1:0x0001]: 'async_initialize' stage succeeded
[0x7221:1:0x1000]: 'async_initialize' stage succeeded
[0x7221:1:0x0020]: 'async_initialize' stage succeeded
[0x7221:1:0x0006]: 'async_initialize' stage succeeded
[0x7221:1:0x0008]: 'async_initialize' stage succeeded
[0x7221:1:0x0006]: 'async_initialize' stage succeeded
[0x7221:1:0x0019]: 'async_initialize' stage succeeded
[0x7221](TRADFRI motion sensor): power source: Battery or Unknown
[0x7221](TRADFRI motion sensor): completed initialization
[0x7221](TRADFRI motion sensor): Device seen - marking the device available and resetting counter
[0x7221](TRADFRI motion sensor): Update device availability -  device available: True - new availability: True - changed: False