Cannot add new devices to ZHA in Home assistant about zigpy-cc

[sanyatuning]

@Adminiuga
Thank you for the suggestion, but with 0xff it responds with error status
0x0F comes form zigbee-herdsman

[sanyatuning]

This message is normal (I will remove it)
What device do you want to pair?
pls provide debug logs

HA config to get debug logs.

logs:
  homeassistant.components.zha: debug
  zigpy: debug
  zigpy_cc: debug

[stevetz]

I am trying to pair Ikea Tradfri bulbs and control outlets, and aqara temp sensors. Since my last message I removed ZHA integration, deleted the zigbee.db, rebooted the vm and tried to start from scratch... Now it wont add the same devices which were initially paired - 3 days ago (HA 0.107.5, since upgraded to 0.109.2).

Here is the log from just now, trying to pair new devices:

2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.zigbee.application] broadcast (0, 54, 0, 0, 0, 0, 1, b'\x01<\x00', <BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>)
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO mgmtPermitJoinReq tsn: 1 {'addrmode': 15, 'dstaddr': 0xfffc, 'duration': 60, 'tcsignificance': 0}
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&'
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=54 data=b'\x00' length=1 fcs=82>
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO mgmtPermitJoinReq tsn: None {'status': 0}
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=203 data=b'<' length=1 fcs=179>
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO permitJoinInd tsn: None {'duration': 60}
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO mgmtPermitJoinReq tsn: None {'addrmode': 15, 'dstaddr': 65532, 'duration': 60, 'tcsignificance': 0}
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&'
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=182 data=b'\x00\x00\x00' length=3 fcs=240>
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO mgmtPermitJoinRsp tsn: None {'srcaddr': 0x0000, 'status': 0}
2020-05-02 11:44:17 WARNING (MainThread) [zigpy_cc.zigbee.application] missing tsn from mgmtPermitJoinRsp, maybe not a reply
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=54 data=b'\x00' length=1 fcs=82>
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO mgmtPermitJoinReq tsn: None {'status': 0}
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=182 data=b'\x00\x00\x00' length=3 fcs=240>
2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO mgmtPermitJoinRsp tsn: None {'srcaddr': 0x0000, 'status': 0}
2020-05-02 11:44:17 WARNING (MainThread) [zigpy_cc.zigbee.application] missing tsn from mgmtPermitJoinRsp, maybe not a reply
2020-05-02 11:44:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=196 data=b'w\x15\x00' length=3 fcs=224>
2020-05-02 11:44:22 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO srcRtgInd tsn: None {'dstaddr': 0x1577, 'relaycount': 0, 'relaylist': []}
2020-05-02 11:44:22 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: srcRtgInd
2020-05-02 11:44:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=196 data=b'w\x15\x00' length=3 fcs=224>
2020-05-02 11:44:22 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO srcRtgInd tsn: None {'dstaddr': 0x1577, 'relaycount': 0, 'relaylist': []}
2020-05-02 11:44:22 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: srcRtgInd
2020-05-02 11:44:24 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=196 data=b'w\x15\x00' length=3 fcs=224>
2020-05-02 11:44:24 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO srcRtgInd tsn: None {'dstaddr': 0x1577, 'relaycount': 0, 'relaylist': []}
2020-05-02 11:44:24 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: srcRtgInd
2020-05-02 11:44:24 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=196 data=b'w\x15\x00' length=3 fcs=224>
2020-05-02 11:44:24 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO srcRtgInd tsn: None {'dstaddr': 0x1577, 'relaycount': 0, 'relaylist': []}
2020-05-02 11:44:24 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: srcRtgInd
2020-05-02 11:44:36 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=196 data=b'w\x15\x00' length=3 fcs=224>
2020-05-02 11:44:36 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO srcRtgInd tsn: None {'dstaddr': 0x1577, 'relaycount': 0, 'relaylist': []}
2020-05-02 11:44:36 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: srcRtgInd
2020-05-02 11:44:36 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=196 data=b'w\x15\x00' length=3 fcs=224>
2020-05-02 11:44:36 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO srcRtgInd tsn: None {'dstaddr': 0x1577, 'relaycount': 0, 'relaylist': []}
2020-05-02 11:44:36 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: srcRtgInd
2020-05-02 11:44:38 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=196 data=b'w\x15\x00' length=3 fcs=224>
2020-05-02 11:44:38 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO srcRtgInd tsn: None {'dstaddr': 0x1577, 'relaycount': 0, 'relaylist': []}
2020-05-02 11:44:38 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: srcRtgInd
2020-05-02 11:44:38 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=196 data=b'w\x15\x00' length=3 fcs=224>
2020-05-02 11:44:38 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO srcRtgInd tsn: None {'dstaddr': 0x1577, 'relaycount': 0, 'relaylist': []}
2020-05-02 11:44:38 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: srcRtgInd
2020-05-02 11:44:41 DEBUG (MainThread) [zigpy_cc.zigbee.application] broadcast (0, 54, 0, 0, 0, 0, 3, b'\x03<\x00', <BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>)
2020-05-02 11:44:41 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO mgmtPermitJoinReq tsn: 3 {'addrmode': 15, 'dstaddr': 0xfffc, 'duration': 60, 'tcsignificance': 0}
2020-05-02 11:44:41 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&'
2020-05-02 11:44:42 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=54 data=b'\x00' length=1 fcs=82>
2020-05-02 11:44:42 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO mgmtPermitJoinReq tsn: None {'status': 0}
2020-05-02 11:44:42 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=182 data=b'\x00\x00\x00' length=3 fcs=240>
2020-05-02 11:44:42 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO mgmtPermitJoinRsp tsn: None {'srcaddr': 0x0000, 'status': 0}
2020-05-02 11:44:42 WARNING (MainThread) [zigpy_cc.zigbee.application] missing tsn from mgmtPermitJoinRsp, maybe not a reply
2020-05-02 11:44:42 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO mgmtPermitJoinReq tsn: None {'addrmode': 15, 'dstaddr': 65532, 'duration': 60, 'tcsignificance': 0}
2020-05-02 11:44:42 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&'
2020-05-02 11:44:42 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=54 data=b'\x00' length=1 fcs=82>
2020-05-02 11:44:42 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO mgmtPermitJoinReq tsn: None {'status': 0}
2020-05-02 11:44:42 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=182 data=b'\x00\x00\x00' length=3 fcs=240>
2020-05-02 11:44:42 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO mgmtPermitJoinRsp tsn: None {'srcaddr': 0x0000, 'status': 0}
2020-05-02 11:44:42 WARNING (MainThread) [zigpy_cc.zigbee.application] missing tsn from mgmtPermitJoinRsp, maybe not a reply

[Adminiuga]

@sanyatuning

One thing I'm noticing for ZDO broadcast we set the "addr mode" to 0x0F

2020-05-02 11:44:17 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x05%6\x0f\xfc\xff<\x00&'

zigpy-cc/zigpy_cc/zigbee/application.py

Line 269 in 649cf94

"addrmode": 0x0F,

Per sniffer it does look like the broadcast goes out, but should the addr mode be 0xFF for broadcast? In Test API pdf revision 1.14 for broadcast it looks like it should be 0xFF

In the next command they expand available dst addr modes

[puddly]

@Adminiuga

The spec PDF has a ton of mistakes. The firmware itself uses 0x0F for the broadcast address mode:

enum
{
  AddrNotPresent = 0,
  AddrGroup = 1,
  Addr16Bit = 2,
  Addr64Bit = 3,
  AddrBroadcast = 15
};

[Adminiuga]

So, it's documented in form of source code then :)

[sanyatuning]

@stevetz
The log looks good to me.
Try unplug the USB stick
If you have another zigbee coordinators turn them off while you pairing.

[stevetz]

Thanks for the suggestion, and sorry for the delay getting back - I've now sorted this... by switching to zigbee2mqtt. However, this may be relevant: I also couldn't get z2m to work! The logs showed that 'unknown' routers were trying to connect, each device was unknown... I unbound the cc2531, rebooted the VM, re bound the usb stick again and it worked fine! So possibly that is the 'fix' for ZHA as well.... at least in my case - however I'm not able now to fiddle with it any more. I already lost a ton of WAF points doing this!!
Thanks

[roger-]

FWIW I had a similar issue where I couldn't pair any new devices with ZHA and would only see the same missing tsn messages (even though paired devices were apparently still working). In my case the fix was to reconnect the CC2531.

Recently I had another issue where the CC2531 would constant disconnect and the solution there was to reflash the firmware. So there's definitely some stability issues related to hardware/firmware.