Cannot pair new Sonoff devices with ZHA

d3x7r0 commented 1 month ago

The problem

I recently bought a couple of extra Sonoff Zigbee devices to add to my network but, when attempting to do so, I found myself unable to have them join.

At first it all seems like it's going fine. I turned the devices on, added them using the UI, and they correctly showed up. But soon the issues started. Even before leaving the screen for adding new devices, the device that previously showed "Initialization complete" will sometimes disappear only to be promptly found again. On the device itself, the LEDs will continue blinking as if they are still stuck in pairing mode.

One thing I did notice is that, every time the screen changes to "Configuring" a new value for "NWK" is present. Not sure if that's relevant or not.

I've tried everything short of completely deleting my zigbee network and rebuilding it from scratch (as you can imagine, this would be incredibly annoying).

Please let me know if there's anything else I can help with.

EDIT: weirdly enough I have a separate Sonoff S26R2ZB that's been on the network for over a year with no signs of the issue. Firmware seems to be the same as well.

What version of Home Assistant Core has the issue?

core-2024.7.4

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

ZHA

Link to integration documentation on our website

https://www.home-assistant.io/integrations/zha/

Diagnostics information

config_entry-zha-c6a0f4bd01446e9997487a48816caa9b.json

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2024-08-03 14:42:22.166 DEBUG (MainThread) [zigpy_znp.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 8, 3, 13, 42, 22, 166416, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x67C2), dst_ep=1, source_route=None, extended_timeout=True, tsn=60, profile_id=260, cluster_id=3, data=Serialized[b'\x01<@\x02\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-08-03 14:42:22.167 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x67C2), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=3, TSN=60, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=0, Data=b'\x01\x3C\x40\x02\x00')
2024-08-03 14:42:22.184 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2024-08-03 14:42:22.425 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.MAC_CHANNEL_ACCESS_FAILURE: 225>, Endpoint=1, TSN=60)
2024-08-03 14:42:22.426 DEBUG (MainThread) [zigpy_znp.zigbee.application] Request failed (Unsuccessful request status code: <Status.MAC_CHANNEL_ACCESS_FAILURE: 225>), retry attempt 1 of 5 (NONE)
2024-08-03 14:42:23.927 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x67C2), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=3, TSN=60, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=0, Data=b'\x01\x3C\x40\x02\x00')
2024-08-03 14:42:23.943 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2024-08-03 14:42:24.267 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.MAC_NO_ACK: 233>, Endpoint=1, TSN=60)
2024-08-03 14:42:24.268 DEBUG (MainThread) [zigpy_znp.zigbee.application] Request failed (Unsuccessful request status code: <Status.MAC_NO_ACK: 233>), retry attempt 2 of 5 (LastGoodRoute)
2024-08-03 14:42:24.769 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestSrcRtg.Req(DstAddr=0x67C2, DstEndpoint=1, SrcEndpoint=1, ClusterId=3, TSN=60, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=0, SourceRoute=[], Data=b'\x01\x3C\x40\x02\x00')
2024-08-03 14:42:24.785 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestSrcRtg.Rsp(Status=<Status.SUCCESS: 0>)
2024-08-03 14:42:25.031 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.MAC_NO_ACK: 233>, Endpoint=1, TSN=60)
2024-08-03 14:42:25.033 DEBUG (MainThread) [zigpy_znp.api] Sending request: ZDO.ExtRouteDisc.Req(Dst=0x67C2, Options=<RouteDiscoveryOptions.UNICAST: 0>, Radius=30)
2024-08-03 14:42:25.050 DEBUG (MainThread) [zigpy_znp.api] Received command: ZDO.ExtRouteDisc.Rsp(Status=<Status.SUCCESS: 0>)
2024-08-03 14:42:26.352 DEBUG (MainThread) [zigpy_znp.zigbee.application] Request failed (Unsuccessful request status code: <Status.MAC_NO_ACK: 233>), retry attempt 3 of 5 (RouteDiscovery|LastGoodRoute)
2024-08-03 14:42:26.811 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x8DF7](TRADFRI bulb E14 WS opal 400lm): Device seen - marking the device available and resetting counter
2024-08-03 14:42:26.812 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x8DF7](TRADFRI bulb E14 WS opal 400lm): Update device availability -  device available: True - new availability: True - changed: False
2024-08-03 14:42:26.855 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x67C2), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=3, TSN=60, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=0, Data=b'\x01\x3C\x40\x02\x00')
2024-08-03 14:42:26.871 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2024-08-03 14:42:27.112 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.MAC_NO_ACK: 233>, Endpoint=1, TSN=60)
2024-08-03 14:42:27.113 DEBUG (MainThread) [zigpy_znp.zigbee.application] Request failed (Unsuccessful request status code: <Status.MAC_NO_ACK: 233>), retry attempt 4 of 5 (RouteDiscovery|LastGoodRoute|IEEEAddress)
2024-08-03 14:42:27.615 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.IEEE: 3>, address=0c:ef:f6:ff:fe:16:74:94), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=3, TSN=60, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=0, Data=b'\x01\x3C\x40\x02\x00')
2024-08-03 14:42:27.632 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2024-08-03 14:42:27.885 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.MAC_CHANNEL_ACCESS_FAILURE: 225>, Endpoint=1, TSN=60)
2024-08-03 14:42:27.886 DEBUG (MainThread) [zigpy_znp.zigbee.application] Request failed (Unsuccessful request status code: <Status.MAC_CHANNEL_ACCESS_FAILURE: 225>), retry attempt 5 of 5 (RouteDiscovery|LastGoodRoute|IEEEAddress)
2024-08-03 14:42:28.308 DEBUG (MainThread) [zigpy_znp.api] Received command: ZDO.LeaveInd.Callback(NWK=0x67C2, IEEE=0c:ef:f6:ff:fe:16:74:94, Request=<Bool.false: 0>, Remove=<Bool.false: 0>, Rejoin=<Bool.false: 0>)
2024-08-03 14:42:28.308 INFO (MainThread) [zigpy_znp.zigbee.application] ZDO device left: ZDO.LeaveInd.Callback(NWK=0x67C2, IEEE=0c:ef:f6:ff:fe:16:74:94, Request=<Bool.false: 0>, Remove=<Bool.false: 0>, Rejoin=<Bool.false: 0>)
2024-08-03 14:42:28.309 INFO (MainThread) [zigpy.application] Device 0x67c2 (0c:ef:f6:ff:fe:16:74:94) left the network

Additional information

The devices in question are:

Sonoff S26R2ZB (2 separate ones)
Sonoff SNZB02D

home-assistant[bot] commented 1 month ago

Hey there @dmulcahey, @adminiuga, @puddly, @thejulianjes, mind taking a look at this issue as it has been labeled with an integration (zha) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of `zha` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign zha` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

_{^{(message by CodeOwnersMention)}}

zha documentation zha source _{^{(message by IssueLinks)}}

dmulcahey commented 1 month ago

zigpy_znp.zigbee.application] Request failed (Unsuccessful request status code: <Status.MAC_CHANNEL_ACCESS_FAILURE: 225>), retry attempt 5 of 5 (RouteDiscovery|LastGoodRoute|IEEEAddress)

Looks like interference. MAC_CHANNEL_ACCESS_FAILURE means that the coordinator can’t communicate on the channel that the network is operating on.

Make sure you have the coordinator on an extension cable (if it’s USB) away from sources of interference such as USB 3 ports, SSDs etc.

d3x7r0 commented 1 month ago

@dmulcahey thanks for the suggestion but nothing has really changed on my setup. I've used an extension to keep the coordinator well away from any source of interference (nothing's plugged in next to it and it's moved way above the rest of the gear by a USB extension) and 16 other devices are still working fine. However I cannot pair a new device.

It's possible there's new interference somewhere in my building (I live in an apartment so that's always likely) but wouldn't that affect the other devices as well?

In fact, one of the Sonoff plugs I was trying to use was one I had previously had on my network and working fine for months. I just had it stored for a while and now brought it back.

D3vil787 commented 1 month ago

I have encountered exactly the same problem. Thermometers SNZB-02D do not complete the setup. At the moment of completion of initialization the process is reset and everything starts again.

home-assistant / core