search

zigpy / zigpy-znp

TI CC2531, CC13x2, CC26x2 radio support for Zigpy and ZHA
GNU General Public License v3.0
144 stars 40 forks source link

'<' not supported between instances of 'ZigbeePacket' and 'ZigbeePacket' #244

Closed wang70880 closed 3 months ago

wang70880 commented 3 months ago

Hi, I meet an issue when running zigpy-znp.

My code is as follows.

zbeeController = ControllerApplication(controller_config)
loop = asyncio.get_event_loop()
loop.run_until_complete(zbeeController.startup(auto_form=True))
print(zbeeController.state.node_info)
print(zbeeController.state.network_info)
loop.run_forever()

Everything goes well until the process of endpoint discovery starts. The error and debugging log is as follows.

[zigpy.device] 2024-03-17 00:29:38 INFO: [0x0000] Requesting 'Node Descriptor'
[zigpy.device] 2024-03-17 00:29:38 DEBUG: [0x0000] Extending timeout for 0x01 request
[__main__] 2024-03-17 00:29:38 DEBUG: Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 3, 16, 16, 29, 38, 136171, tzinfo=datetime.timezone.utc), 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=True, tsn=1, profile_id=0, cluster_id=<ZDOCmd.Node_Desc_req: 0x0002>, data=Serialized[b'\x01\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
[zigpy.application] 2024-03-17 00:29:38 DEBUG: Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 3, 16, 16, 29, 38, 136171, tzinfo=datetime.timezone.utc), 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=1, profile_id=0, cluster_id=<ZDOCmd.Node_Desc_req: 0x0002>, data=Serialized[b'\x01\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
[zigpy.application] 2024-03-17 00:29:38 DEBUG: Received frame on uninitialized device <ZNPCoordinator model='Coordinator' manuf='Texas Instruments' nwk=0x0000 ieee=00:12:4b:00:18:e7:03:4c is_initialized=False> from ep 0 to ep 0, cluster ZDOCmd.Node_Desc_req: Serialized[b'\x01\x00\x00']
[zigpy.zdo] 2024-03-17 00:29:38 DEBUG: [0x0000:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000]
[zigpy.zdo] 2024-03-17 00:29:38 DEBUG: [0x0000:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000])
[zigpy_znp.api] 2024-03-17 00:29:38 DEBUG: Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x0000), DstEndpoint=0, DstPanId=0x0000, SrcEndpoint=0, ClusterId=2, TSN=1, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=0, Data=b'\x01\x00\x00')
[zigpy_znp.uart] 2024-03-17 00:29:38 INFO: Sending data: b'\xFE\x17\x24\x02\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02\x00\x01\x20\x00\x03\x00\x01\x00\x00\x12'
[zigpy_znp.uart] 2024-03-17 00:29:38 INFO: <-- Received data: b'\xFE\x01\x64\x02\x00\x67\xFE\x12\x45\x82\x00\x00\x00\x00\x00\x00\x40\x8F\x00\x00\x50\xA0\x00\x01\x2A\xA0\x00\x00\x61\xFE\x19\x45\xFF\x00\x00\x00\x02\x80\x00\x01\x00\x00\x00\x00\x00\x00\x40\x8F\x00\x00\x50\xA0\x00\x01\x2A\xA0\x00\x00\x94'
[zigpy_znp.uart] 2024-03-17 00:29:38 INFO: Parsed frame: TransportFrame(payload=GeneralFrame(header=CommandHeader(id=0x02, subsystem=Subsystem.AF, type=CommandType.SRSP), data=b'\x00'))
[zigpy_znp.api] 2024-03-17 00:29:38 DEBUG: Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
[zigpy_znp.uart] 2024-03-17 00:29:38 INFO: Parsed frame: TransportFrame(payload=GeneralFrame(header=CommandHeader(id=0x82, subsystem=Subsystem.ZDO, type=CommandType.AREQ), data=b'\x00\x00\x00\x00\x00\x00\x40\x8F\x00\x00\x50\xA0\x00\x01\x2A\xA0\x00\x00'))
[zigpy_znp.api] 2024-03-17 00:29:38 DEBUG: Received command: ZDO.NodeDescRsp.Callback(Src=0x0000, Status=<Status.SUCCESS: 0>, NWK=0x0000, NodeDescriptor=NullableNodeDescriptor(logical_type=<LogicalType.Coordinator: 0>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.AlternatePanCoordinator|FullFunctionDevice|MainsPowered|RxOnWhenIdle|AllocateAddress: 143>, manufacturer_code=0, maximum_buffer_size=80, maximum_incoming_transfer_size=160, server_mask=10753, maximum_outgoing_transfer_size=160, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=True, *is_coordinator=True, *is_end_device=False, *is_full_function_device=True, *is_mains_powered=True, *is_receiver_on_when_idle=True, *is_router=False, *is_security_capable=False))
[zigpy_znp.api] 2024-03-17 00:29:38 DEBUG: Command was not handled
[zigpy_znp.uart] 2024-03-17 00:29:38 INFO: Parsed frame: TransportFrame(payload=GeneralFrame(header=CommandHeader(id=0xFF, subsystem=Subsystem.ZDO, type=CommandType.AREQ), data=b'\x00\x00\x00\x02\x80\x00\x01\x00\x00\x00\x00\x00\x00\x40\x8F\x00\x00\x50\xA0\x00\x01\x2A\xA0\x00\x00'))
[zigpy_znp.api] 2024-03-17 00:29:38 DEBUG: Received command: ZDO.MsgCbIncoming.Callback(Src=0x0000, IsBroadcast=<Bool.false: 0>, ClusterId=32770, SecurityUse=0, TSN=1, MacDst=0x0000, Data=b'\x00\x00\x00\x00\x40\x8F\x00\x00\x50\xA0\x00\x01\x2A\xA0\x00\x00')
[zigpy.application] 2024-03-17 00:29:38 DEBUG: Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 3, 16, 16, 29, 38, 169185, tzinfo=datetime.timezone.utc), 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=1, profile_id=0, cluster_id=32770, data=Serialized[b'\x01\x00\x00\x00\x00@\x8f\x00\x00P\xa0\x00\x01*\xa0\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
[zigpy.application] 2024-03-17 00:29:38 DEBUG: Received frame on uninitialized device <ZNPCoordinator model='Coordinator' manuf='Texas Instruments' nwk=0x0000 ieee=00:12:4b:00:18:e7:03:4c is_initialized=False> from ep 0 to ep 0, cluster 32770: Serialized[b'\x01\x00\x00\x00\x00@\x8f\x00\x00P\xa0\x00\x01*\xa0\x00\x00']
[zigpy.device] 2024-03-17 00:29:38 INFO: [0x0000] Got Node Descriptor: NodeDescriptor(logical_type=<LogicalType.Coordinator: 0>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.AlternatePanCoordinator|FullFunctionDevice|MainsPowered|RxOnWhenIdle|AllocateAddress: 143>, manufacturer_code=0, maximum_buffer_size=80, maximum_incoming_transfer_size=160, server_mask=10753, maximum_outgoing_transfer_size=160, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=True, *is_coordinator=True, *is_end_device=False, *is_full_function_device=True, *is_mains_powered=True, *is_receiver_on_when_idle=True, *is_router=False, *is_security_capable=False)
[zigpy.device] 2024-03-17 00:29:38 INFO: [0x0000] Discovering endpoints
[__main__] 2024-03-17 00:29:38 DEBUG: Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 3, 16, 16, 29, 38, 170190, tzinfo=datetime.timezone.utc), 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=2, profile_id=0, cluster_id=<ZDOCmd.Active_EP_req: 0x0005>, data=Serialized[b'\x02\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
[zigpy.application] 2024-03-17 00:29:38 DEBUG: Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 3, 16, 16, 29, 38, 170190, tzinfo=datetime.timezone.utc), 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=2, profile_id=0, cluster_id=<ZDOCmd.Active_EP_req: 0x0005>, data=Serialized[b'\x02\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
[zigpy.application] 2024-03-17 00:29:38 DEBUG: Received frame on uninitialized device <ZNPCoordinator model='Coordinator' manuf='Texas Instruments' nwk=0x0000 ieee=00:12:4b:00:18:e7:03:4c is_initialized=False> from ep 0 to ep 0, cluster ZDOCmd.Active_EP_req: Serialized[b'\x02\x00\x00']
[zigpy.device] 2024-03-17 00:29:38 WARNING: Device <ZNPCoordinator model='Coordinator' manuf='Texas Instruments' nwk=0x0000 ieee=00:12:4b:00:18:e7:03:4c is_initialized=False> failed to initialize due to unexpected error
Traceback (most recent call last):
  File "C:\ProgramData\anaconda3\Lib\site-packages\zigpy\device.py", line 200, in initialize
    await self._initialize()
  File "C:\ProgramData\anaconda3\Lib\site-packages\zigpy\util.py", line 131, in retry
    return await func()
           ^^^^^^^^^^^^
  File "C:\ProgramData\anaconda3\Lib\site-packages\zigpy\device.py", line 229, in _initialize
    status, _, endpoints = await self.zdo.Active_EP_req(self.nwk)
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\ProgramData\anaconda3\Lib\site-packages\zigpy\device.py", line 334, in request
    await send_request()
  File "C:\ProgramData\anaconda3\Lib\site-packages\zigpy\application.py", line 842, in request
    await self.send_packet(
  File "C:\Users\Administrator\Downloads\zigpy-znp-dev\zigpy-znp-dev\zigbee.py", line 970, in send_packet
    await self._send_request_raw(
  File "C:\Users\Administrator\Downloads\zigpy-znp-dev\zigpy-znp-dev\zigbee.py", line 830, in _send_request_raw
    self.packet_received(
  File "C:\ProgramData\anaconda3\Lib\site-packages\zigpy\application.py", line 1061, in packet_received
    return device.packet_received(packet)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\ProgramData\anaconda3\Lib\site-packages\zigpy\device.py", line 393, in packet_received
    if self._packet_debouncer.filter(
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\ProgramData\anaconda3\Lib\site-packages\zigpy\datastructures.py", line 264, in filter
    heapq.heappush(self._queue, (-(now + expire_in), obj))
TypeError: '<' not supported between instances of 'ZigbeePacket' and 'ZigbeePacket'

Could anyone help me to identify the root cause and address the TypeError issue? Thanks a lot.

puddly commented 3 months ago

I believe this may actually be a Windows problem. We rely on the resolution of asyncio.get_running_loop().time() and don't expect that two subsequent invocations to return the same time. On Windows, the resolution of the clock seems to be too low and this happens.

Until a fix lands in zigpy, you may be able to use it within WSL2.

wang70880 commented 3 months ago

Thanks for your reply. I will migrate the project to ubuntu and test it.

wang70880 commented 3 months ago

Problems solved after I switched to Ubuntu, which follows puddly's statements. Thanks.