zigpy-zigate icon indicating copy to clipboard operation
zigpy-zigate copied to clipboard

Unable to join device via router ("No such device 0x0000")

Open ruimarinho opened this issue 3 years ago • 2 comments

I have a CC2531-based router firmware (from the Z2M project) which I was able to add via ZHA to the zigate integration. However, even if the device is recognized as a router, I am unable to add devices that apparently are routing their join messages via these routers.

image

The test is simple - if I try adding an Aqara Temp sensor next to a paired router, I get this:

2021-06-12 21:55:20 DEBUG (MainThread) [zigpy_zigate.zigbee.application] No such device 0x85dd
2021-06-12 21:55:20 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 8002001f05000104040301010285dd020000180d0a000029db03140028ff100029932663
2021-06-12 21:55:20 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8002 b'000104040301010285dd020000180d0a000029db03140028ff1000299326' LQI:99
2021-06-12 21:55:20 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 260, 1027, 1, 1, <Address address_mode=ADDRESS_MODE.NWK address=0x85dd>, <Address address_mode=ADDRESS_MODE.NWK address=0x0000>, b'\x18\r\n\x00\x00)\xdb\x03\x14\x00(\xff\x10\x00)\x93&']

If I power off the router and I attempt a direct coordinator pairing, or if I move closers to the coordinator than the router, I can successfully add the device.

I'm on firmware 3.1e with the optimised PDM version.

Curiously, using homeassistant-zigate, routing appeared to work fine - so either it wasn't working at all and I was being mislead by the results, or it was working flawlessly as I never had a problem with it.

The same thing happens with an IKEA-based router.

Any idea @doudz ?

ruimarinho avatar Jun 17 '21 18:06 ruimarinho

Seems like it's happening even if pairing directly:

2021-06-27 01:46:32 DEBUG (MainThread) [zigpy_zigate.zigbee.application] Broadcast not implemented.
2021-06-27 01:46:32 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0049 b'fffc3c00'
2021-06-27 01:46:32 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00I\x00\x04r\xff\xfc<\x00'
2021-06-27 01:46:32 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10I\x02\x10\x02\x14r\xff\xfc<\x02\x10'
2021-06-27 01:46:32 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000090b006f004902a7010000
2021-06-27 01:46:32 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'006f004902a70100' LQI:0
2021-06-27 01:46:32 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 111, 73, b'\x02\xa7\x01\x00']
2021-06-27 01:46:32 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 8012000a3f00000002fffca7010000
2021-06-27 01:46:32 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8012 b'00000002fffca70100' LQI:0
2021-06-27 01:46:32 ERROR (MainThread) [zigpy_zigate.api] Received unhandled response 0x8012
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 8002001ac80000000013000002643502fffd6f356486bd7b04008d15008072
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8002 b'0000000013000002643502fffd6f356486bd7b04008d150080' LQI:114
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 19, 0, 0, <Address address_mode=ADDRESS_MODE.NWK address=0x6435>, <Address address_mode=ADDRESS_MODE.NWK address=0xfffd>, b'o5d\x86\xbd{\x04\x00\x8d\x15\x00\x80']
**2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.zigbee.application] No such device 0x6435**
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 87010005870000040000
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8701 b'00000400' LQI:0
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0]
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 8002002eee0001040000010102643502000018000a050042156c756d692e73656e736f725f776c65616b2e6171310100200472
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8002 b'0001040000010102643502000018000a050042156c756d692e73656e736f725f776c65616b2e61713101002004' LQI:114
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 260, 0, 1, 1, <Address address_mode=ADDRESS_MODE.NWK address=0x6435>, <Address address_mode=ADDRESS_MODE.NWK address=0x0000>, b'\x18\x00\n\x05\x00B\x15lumi.sensor_wleak.aq1\x01\x00 \x04']
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.zigbee.application] No such device 0x6435
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80020038a2000104000001010264350200001c5f11010a01ff42220121d10b03281e0421a8010521250006240100000000082104020a2115fd64100072
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8002 b'000104000001010264350200001c5f11010a01ff42220121d10b03281e0421a8010521250006240100000000082104020a2115fd641000' LQI:114
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 260, 0, 1, 1, <Address address_mode=ADDRESS_MODE.NWK address=0x6435>, <Address address_mode=ADDRESS_MODE.NWK address=0x0000>, b'\x1c_\x11\x01\n\x01\xffB"\x01!\xd1\x0b\x03(\x1e\x04!\xa8\x01\x05!%\x00\x06$\x01\x00\x00\x00\x00\x08!\x04\x02\n!\x15\xfdd\x10\x00']
2021-06-27 01:46:54 DEBUG (MainThread) [zigpy_zigate.zigbee.application] No such device 0x6435
2021-06-27 01:47:01 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800200519a000104000001010264350200001c5f11020a050042156c756d692e73656e736f725f776c65616b2e61713101ff42220121d10b03281e0421a8010521250006240000000000082104020a2115fd64100072
2021-06-27 01:47:01 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8002 b'000104000001010264350200001c5f11020a050042156c756d692e73656e736f725f776c65616b2e61713101ff42220121d10b03281e0421a8010521250006240000000000082104020a2115fd641000' LQI:114
2021-06-27 01:47:01 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 260, 0, 1, 1, <Address address_mode=ADDRESS_MODE.NWK address=0x6435>, <Address address_mode=ADDRESS_MODE.NWK address=0x0000>, b'\x1c_\x11\x02\n\x05\x00B\x15lumi.sensor_wleak.aq1\x01\xffB"\x01!\xd1\x0b\x03(\x1e\x04!\xa8\x01\x05!%\x00\x06$\x00\x00\x00\x00\x00\x08!\x04\x02\n!\x15\xfdd\x10\x00']
2021-06-27 01:47:01 DEBUG (MainThread) [zigpy_zigate.zigbee.application] No such device 0x6435
2021-06-27 01:47:02 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800200519b000104000001010264350200001c5f11030a050042156c756d692e73656e736f725f776c65616b2e61713101ff42220121d10b03281e0421a8010521250006240000000000082104020a2115fd64100072
2021-06-27 01:47:02 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8002 b'000104000001010264350200001c5f11030a050042156c756d692e73656e736f725f776c65616b2e61713101ff42220121d10b03281e0421a8010521250006240000000000082104020a2115fd641000' LQI:114
2021-06-27 01:47:02 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 260, 0, 1, 1, <Address address_mode=ADDRESS_MODE.NWK address=0x6435>, <Address address_mode=ADDRESS_MODE.NWK address=0x0000>, b'\x1c_\x11\x03\n\x05\x00B\x15lumi.sensor_wleak.aq1\x01\xffB"\x01!\xd1\x0b\x03(\x1e\x04!\xa8\x01\x05!%\x00\x06$\x00\x00\x00\x00\x00\x08!\x04\x02\n!\x15\xfdd\x10\x00']
2021-06-27 01:47:09 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800200519c000104000001010264350200001c5f11040a050042156c756d692e73656e736f725f776c65616b2e61713101ff42220121d10b03281e0421a8010521250006240000000000082104020a2115fd64100072
2021-06-27 01:47:09 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8002 b'000104000001010264350200001c5f11040a050042156c756d692e73656e736f725f776c65616b2e61713101ff42220121d10b03281e0421a8010521250006240000000000082104020a2115fd641000' LQI:114
2021-06-27 01:47:09 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 260, 0, 1, 1, <Address address_mode=ADDRESS_MODE.NWK address=0x6435>, <Address address_mode=ADDRESS_MODE.NWK address=0x0000>, b'\x1c_\x11\x04\n\x05\x00B\x15lumi.sensor_wleak.aq1\x01\xffB"\x01!\xd1\x0b\x03(\x1e\x04!\xa8\x01\x05!%\x00\x06$\x00\x00\x00\x00\x00\x08!\x04\x02\n!\x15\xfdd\x10\x00']
2021-06-27 01:47:09 DEBUG (MainThread) [zigpy_zigate.zigbee.application] No such device 0x6435
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80020015540001040006080102fd1502000000790a0000200072
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8002 b'0001040006080102fd1502000000790a00002000' LQI:114
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 260, 6, 8, 1, <Address address_mode=ADDRESS_MODE.NWK address=0xfd15>, <Address address_mode=ADDRESS_MODE.NWK address=0x0000>, b'\x00y\n\x00\x00 \x00']
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy.zcl] [0xfd15:8:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=121 command_id=Command.Report_Attributes>
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy.zcl] [0xfd15:8:0x0006] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=uint8_t, value=0>)]]
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy.zcl] [0xfd15:8:0x0006] Attribute report received: on_off=0
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.zigbee.application] request (0xFD15, 260, 6, 1, 8, 121, b'\x18y\x0b\n\x00', False, False)
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0530 b'02fd1501080006010400000518790b0a00'
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x050\x00\x11\xa1\x02\xfd\x15\x01\x08\x00\x06\x01\x04\x00\x00\x05\x18y\x0b\n\x00'
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x150\x02\x10\x11\xa1\x02\x12\xfd\x15\x02\x11\x02\x18\x02\x10\x02\x16\x02\x11\x02\x14\x02\x10\x02\x10\x02\x15\x18y\x02\x1b\x02\x1a\x02\x10'
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 8012000ad500010802fd15ac000200
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8012 b'00010802fd15ac0002' LQI:0
2021-06-27 01:47:11 ERROR (MainThread) [zigpy_zigate.api] Received unhandled response 0x8012
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 8012000a2b00010802fd15ad0002ff
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8012 b'00010802fd15ad0002' LQI:255
2021-06-27 01:47:11 ERROR (MainThread) [zigpy_zigate.api] Received unhandled response 0x8012
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 801100082500fd15010006acff
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8011 b'00fd15010006ac' LQI:255
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0xfd15, 1, 6, 172]
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.zigbee.application] ACK Data received 172 0
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80000009bf00ae053001ae000200
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'00ae053001ae0002' LQI:0
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 174, 1328, b'\x01\xae\x00\x02']
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80110008db00fd15010006ad00
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8011 b'00fd15010006ad' LQI:0
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0xfd15, 1, 6, 173]
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.zigbee.application] ACK Data received 173 0
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 8012000ad400010802fd15ae000100
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8012 b'00010802fd15ae0001' LQI:0
2021-06-27 01:47:11 ERROR (MainThread) [zigpy_zigate.api] Received unhandled response 0x8012
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80110008d800fd15010006ae00
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8011 b'00fd15010006ae' LQI:0
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0xfd15, 1, 6, 174]
2021-06-27 01:47:11 DEBUG (MainThread) [zigpy_zigate.zigbee.application] ACK Data received 174 0

ruimarinho avatar Jun 27 '21 00:06 ruimarinho

Suggest report to https://github.com/zigpy/zha-device-handlers/issues with more info on exact firmware used (maybe with link).

Hedda avatar Nov 16 '21 14:11 Hedda