Skip to content

Difference in behaviour between bellows and zigpy-znp while processing frame #264

@candeodevelopment

Description

@candeodevelopment

We've had some customers reporting issues with one of our products ( https://candeo.io/store/zigbee-5-button-remote-with-rotary-dial ) under ZHA.

Further investigation has narrowed the problem down to customers using TI based Zigbee radios, which use the zigpy-znp library.

Customers using Ember based Zigbee radios, using the bellows library, don't experience the problem.

bellows:

2025-10-17 11:55:46.266 DEBUG (bellows.thread_0) [bellows.ash] Received data 6408b1a97d312a15b65897b524ab1593499ce08f6de49498befac70b88fd7d5e
2025-10-17 11:55:46.270 DEBUG (bellows.thread_0) [bellows.ash] Received data 2fa4e997757e
2025-10-17 11:55:46.271 DEBUG (bellows.thread_0) [bellows.ash] Received frame DataFrame(frm_num=6, re_tx=0, ack_num=4, ezsp_frame=b'J\x90\x01E\x00\x00\x04\x01\x03\xff\x01\x01@\x01\x00\x00\xae\xa8\xc6\tZ\xff5\x07\x01h\x01\x01\x00\x10\x03\x02')
2025-10-17 11:55:46.272 DEBUG (bellows.thread_0) [bellows.ash] Sending frame AckFrame(res=0, ncp_ready=0, ack_num=7) + FLAG
2025-10-17 11:55:46.273 DEBUG (bellows.thread_0) [bellows.ash] Sending data 87009f7e
2025-10-17 11:55:46.280 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=65283, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=174), 'lastHopLqi': 168, 'lastHopRssi': -58, 'sender': 0x5A09, 'bindingIndex': 255, 'addressIndex': 53, 'messageContents': b'\x01h\x01\x01\x00\x10\x03'}
2025-10-17 11:55:46.281 DEBUG (MainThread) [bellows.ezsp.protocol] Frame contains trailing data: b'\x02'
2025-10-17 11:55:46.282 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=65283, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=174), 168, -58, 0x5A09, 255, 53, b'\x01h\x01\x01\x00\x10\x03']

zigpy-znp:

2025-10-17 00:28:20.559 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2025, 10, 16, 20, 28, 20, 557536, tzinfo=datetime.timezone.utc), priority=None, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xE132), 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=65283, data=Serialized[b'\x01t\x01\x03\x01\x01\x19'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2025-10-17 00:28:20.559 DEBUG (MainThread) [zigpy.application] Could not parse ZDO message from packet
2025-10-17 00:28:20.560 DEBUG (MainThread) [zigpy.device] [0xe132] Failed to parse packet ZigbeePacket(timestamp=datetime.datetime(2025, 10, 16, 20, 28, 20, 557536, tzinfo=datetime.timezone.utc), priority=None, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xE132), 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=65283, data=Serialized[b'\x01t\x01\x03\x01\x01\x19'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
Traceback (most recent call last):
File "/usr/local/lib/python3.13/site-packages/zigpy/device.py", line 824, in packet_received
cmd = self._parse_packet_command(packet, endpoint, zcl_cluster)
File "/usr/local/lib/python3.13/site-packages/zigpy/device.py", line 768, in _parse_packet_command
_, cmd = endpoint.deserialize(packet.cluster_id, data)
~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.13/site-packages/zigpy/zdo/init.py", line 42, in deserialize
raise ValueError(f"Invalid ZDO cluster ID: 0x{cluster_id:04X}")
ValueError: Invalid ZDO cluster ID: 0xFF03

The above exception was the direct cause of the following exception:

zigpy.exceptions.ParsingError
2025-10-17 00:28:20.866 ERROR (MainThread) [zigpy_znp.uart] Received an exception while passing frame to API: TransportFrame(payload=GeneralFrame(header=CommandHeader(id=0x83, subsystem=Subsystem.ZDO, type=CommandType.AREQ), data=b'\x32\xE1\x75\x01\x03\x01\x01\x01'))
Traceback (most recent call last):
File "/usr/local/lib/python3.13/site-packages/zigpy_znp/uart.py", line 56, in data_received
self._api.frame_received(frame.payload)
~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.13/site-packages/zigpy_znp/api.py", line 860, in frame_received
command = command_cls.from_frame(frame, align=self.nvram.align_structs)
File "/usr/local/lib/python3.13/site-packages/zigpy_znp/types/commands.py", line 433, in from_frame
raise ValueError(
f"Frame {frame} contains trailing data after parsing: {data}"
)
ValueError: Frame GeneralFrame(header=CommandHeader(id=0x83, subsystem=Subsystem.ZDO, type=CommandType.AREQ), data=b'\x32\xE1\x75\x01\x03\x01\x01\x01') contains trailing data after parsing: b'\x01'
2025-10-17 00:28:20.868 WARNING (MainThread) [zigpy_znp.zigbee.application] Failed to deserialize ZDO packet
Traceback (most recent call last):
File "/usr/local/lib/python3.13/site-packages/zigpy_znp/zigbee/application.py", line 443, in on_zdo_message
zdo_hdr, zdo_args = self._device.zdo.deserialize(
~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
cluster_id=packet.cluster_id, data=packet.data.serialize()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
)
^
File "/usr/local/lib/python3.13/site-packages/zigpy/zdo/init.py", line 42, in deserialize
raise ValueError(f"Invalid ZDO cluster ID: 0x{cluster_id:04X}")
ValueError: Invalid ZDO cluster ID: 0xFF03

I guess that ultimately the device may have a bug if it's sending spurious data in the frame, but it does work OK across all our other supported platforms (Z2M, Hubitat, SmartThings, etc).

It does seem that there is a difference in behaviour between how bellows and zigpy-znp are handling frames that contain trailing data?

bellows logs an error if the frame contains trailing data, but otherwise moves on and processes the data:

https://github.com/zigpy/bellows/blob/cdd12173f044da35962bc433dc4f7b250e0fba52/bellows/ezsp/protocol.py#L184

zigpy-znp actually raises an error, so further processing of the data stops:

raise ValueError(

Should the behaviour between bellows & zigpy-znp be consistent?

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions