Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge 🌉, get rid of your proprietary Zigbee bridges 🔨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
12.35k stars 1.69k forks source link

[ezsp] Ikea Smartplug not joining, errors out with "status":"failed"},"type":"device_interview"}' #13964

Closed tomm1ed closed 2 years ago

tomm1ed commented 2 years ago

What happened?

Silvercrest Zigbee Gateway rooted through instruction at https://zigbee.blakadder.com/Lidl_TYGWZ-01.html zigbee2mqtt running in docker

Trying to add Ikea Smart Plug (https://www.zigbee2mqtt.io/devices/E1603_E1702_E1708.html) to zigbee2mqtt. Device does pair but ends up as 'Unsupported'. Said Smart Plug can connect to the Ikea Gateway and was updated to the newest Firmware (2.3.089) using the Ikea Home Smart app prior to trying to connect to zigbee2mqtt. Both the Lidl Gateway and the Plug have been power cycled but the Interview keeps failing. Plug also works when connected to Zigate stick

zigbee2mqtt log: 2022-09-11 11:09:27Device '0x588e81fffe6aef16' joined info 2022-09-11 11:09:27MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x588e81fffe6aef16","ieee_address":"0x588e81fffe6aef16"},"type":"device_joined"}' info 2022-09-11 11:09:27MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"message":{"friendly_name":"0x588e81fffe6aef16"},"type":"device_connected"}' info 2022-09-11 11:09:27Starting interview of '0x588e81fffe6aef16' info 2022-09-11 11:09:27MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x588e81fffe6aef16","ieee_address":"0x588e81fffe6aef16","status":"started"},"type":"device_interview"}' info 2022-09-11 11:09:27MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"message":"interview_started","meta":{"friendly_name":"0x588e81fffe6aef16"},"type":"pairing"}' error 2022-09-11 11:12:27Failed to interview '0x588e81fffe6aef16', device has not successfully been paired info 2022-09-11 11:12:27MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0x588e81fffe6aef16","ieee_address":"0x588e81fffe6aef16","status":"failed"},"type":"device_interview"}' info 2022-09-11 11:12:27MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"message":"interview_failed","meta":{"friendly_name":"0x588e81fffe6aef16"},"type":"pairing"}'

What did you expect to happen?

The plug pairs successfully

How to reproduce it (minimal and precise)

Put zigbee2mqtt in pairing mode Push the reset button on the plug Wait

Zigbee2MQTT version

1.27.2

Adapter firmware version

6.7.8.0 build 373

Adapter

Silvercrest Zigbee Gateway Model TYGWZ-01 manufactured by Lidl

Debug log

zigbee2mqtt-debug.log

Koenkk commented 2 years ago

It seems the device doesn't connect properly. I will need to have a sniff to debug this further, can you provide one when trying to pair the device?

https://www.zigbee2mqtt.io/advanced/zigbee/04_sniff_zigbee_traffic.html#with-cc2531

tomm1ed commented 2 years ago

It seems the device doesn't connect properly. I will need to have a sniff to debug this further, can you provide one when trying to pair the device?

https://www.zigbee2mqtt.io/advanced/zigbee/04_sniff_zigbee_traffic.html#with-cc2531

Hi Koen, thanks for the swift reply. I will do this next week as I will be traveling this week. Hopefully we can get to the bottom of this

sujithg9 commented 2 years ago

@Koenkk @tomm1ed I might be having a similar issue with my Ikea motion sensor which I have listed under the below issue and I have also attached some debug logging in there .. hope that helps.

https://github.com/Koenkk/zigbee2mqtt/issues/13930

tomm1ed commented 2 years ago

It seems the device doesn't connect properly. I will need to have a sniff to debug this further, can you provide one when trying to pair the device?

https://www.zigbee2mqtt.io/advanced/zigbee/04_sniff_zigbee_traffic.html#with-cc2531

Hi Koen,

As promised the capture: Zigbee-capture.zip

Koenkk commented 2 years ago

@tomm1ed today a pairing improvement has been merged for EZSP adapters; can you try it? (https://github.com/Koenkk/zigbee-herdsman/pull/580).

Changes will be available in the dev branch in a few hours from now. (https://www.zigbee2mqtt.io/advanced/more/switch-to-dev-branch.html)

If it doesn't help; please provide me a sniff again.

tomm1ed commented 2 years ago

@Koenkk updated to 1.27.2-dev commit: 9b4a03c and the plug doesn't even register for inclusion When going back to 1.27.2 commit: 7dc48fb the plug once more joins but the plug of course again ends up as interview failed/unsupported

Here's the capture: zigbee-9b4a03c.zip

kirovilya commented 2 years ago

@tomm1ed please wait for merge PR https://github.com/Koenkk/zigbee-herdsman/pull/581 and then check again

tomm1ed commented 2 years ago

@tomm1ed please wait for merge PR Koenkk/zigbee-herdsman#581 and then check again

Hi @kirovilya thanks for the reply. When is this PR expected to be merged into the dev channel?

kirovilya commented 2 years ago

@tomm1ed I think - today, later

Koenkk commented 2 years ago

It is in now.

tomm1ed commented 2 years ago

It is in now.

Thank you @Koenkk (and @kirovilya of course), will need some time to retest. WIll let you know ASAP

samuelthng commented 2 years ago

Seems I have the same issue for a couple of Tuya devices and another IKEA GU10 bulbs. Also on EZSP adapter.

I'm on HAOS, wondering if I could help test with the dev build on HA Add-On store?

samuelthng commented 2 years ago

I've tried pairing to the devices in question using edge, but it seems not to pick up the devices at all instead.

samuelthng commented 2 years ago

Hello, wanted to check if anyone else with pairing issues faced this:

Not sure if it's related to the pairing issue but wanted to get some opinions and eyes on this. https://github.com/Koenkk/zigbee-herdsman/blame/85c277f82204be6d7419df396896645da549def6/src/adapter/ezsp/driver/driver.ts#L298

2022-09-26T15:30:37.090Z zigbee-herdsman:adapter:ezsp:ezsp Time to watchdog ... 0
2022-09-26T15:30:37.090Z zigbee-herdsman:adapter:ezsp:ezsp ==> nop: null
2022-09-26T15:30:37.090Z zigbee-herdsman:adapter:ezsp:ezsp ==> {"_cls_":"nop","_id_":5,"_isRequest_":true}
2022-09-26T15:30:37.090Z zigbee-herdsman:adapter:ezsp:uart --> DATA (0,2,0): 6000010500
2022-09-26T15:30:37.091Z zigbee-herdsman:adapter:ezsp:uart --> [022221a9512a7d33367e]
2022-09-26T15:30:37.091Z zigbee-herdsman:adapter:ezsp:uart -?- waiting (1)
2022-09-26T15:30:37.095Z zigbee-herdsman:adapter:ezsp:uart <-- [2122a1a9512a35e67e]
2022-09-26T15:30:37.095Z zigbee-herdsman:adapter:ezsp:uart <-- DATA (2,1,0): 2122a1a9512a35e67e
2022-09-26T15:30:37.095Z zigbee-herdsman:adapter:ezsp:uart --> ACK  (3)
2022-09-26T15:30:37.095Z zigbee-herdsman:adapter:ezsp:uart --> [83401b7e]
2022-09-26T15:30:37.095Z zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 6080010500
2022-09-26T15:30:37.095Z zigbee-herdsman:adapter:ezsp:ezsp <== 0x5: {"_id_":5,"_cls_":"nop","_isRequest_":false}
2022-09-26T15:30:37.096Z zigbee-herdsman:adapter:ezsp:uart -+- waiting (1) success
2022-09-26T15:30:44.368Z zigbee-herdsman:adapter:ezsp:uart <-- [3122b1a9702ae2cb24d2fb7d5d946d53ed9d4e27abe5037e]
2022-09-26T15:30:44.368Z zigbee-herdsman:adapter:ezsp:uart <-- DATA (3,1,0): 3122b1a9702ae2cb24d2fb7d946d53ed9d4e27abe5037e00
2022-09-26T15:30:44.368Z zigbee-herdsman:adapter:ezsp:uart --> ACK  (4)
2022-09-26T15:30:44.369Z zigbee-herdsman:adapter:ezsp:uart --> [8430fc7e]
2022-09-26T15:30:44.369Z zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 6090012400f7797d46b1583e38c1a40100000008
2022-09-26T15:30:44.369Z zigbee-herdsman:adapter:ezsp:ezsp <== 0x24: {"_id_":36,"_cls_":"trustCenterJoinHandler","_isRequest_":false,"newNodeId":31223,"newNodeEui64":[164,193,56,62,88,177,70,125],"status":1,"policyDecision":0,"parentOfNewNodeId":0}
2022-09-26T15:30:47.091Z zigbee-herdsman:adapter:ezsp:ezsp Time to watchdog ... 0
2022-09-26T15:30:47.091Z zigbee-herdsman:adapter:ezsp:ezsp ==> nop: null
2022-09-26T15:30:47.091Z zigbee-herdsman:adapter:ezsp:ezsp ==> {"_cls_":"nop","_id_":5,"_isRequest_":true}
2022-09-26T15:30:47.091Z zigbee-herdsman:adapter:ezsp:uart --> DATA (1,4,0): 6100010500
2022-09-26T15:30:47.091Z zigbee-herdsman:adapter:ezsp:uart --> [142321a9512a2e027e]
2022-09-26T15:30:47.092Z zigbee-herdsman:adapter:ezsp:uart -?- waiting (2)
2022-09-26T15:30:47.096Z zigbee-herdsman:adapter:ezsp:uart <-- [4223a1a9512a0e4f7e]
2022-09-26T15:30:47.096Z zigbee-herdsman:adapter:ezsp:uart <-- DATA (4,2,0): 4223a1a9512a0e4f7e
2022-09-26T15:30:47.096Z zigbee-herdsman:adapter:ezsp:uart --> ACK  (5)
2022-09-26T15:30:47.096Z zigbee-herdsman:adapter:ezsp:uart --> [8520dd7e]
2022-09-26T15:30:47.096Z zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 6180010500
2022-09-26T15:30:47.096Z zigbee-herdsman:adapter:ezsp:ezsp <== 0x5: {"_id_":5,"_cls_":"nop","_isRequest_":false}
2022-09-26T15:30:47.096Z zigbee-herdsman:adapter:ezsp:uart -+- waiting (2) success
2022-09-26T15:30:57.091Z zigbee-herdsman:adapter:ezsp:ezsp Time to watchdog ... 0
2022-09-26T15:30:57.092Z zigbee-herdsman:adapter:ezsp:ezsp ==> nop: null
2022-09-26T15:30:57.092Z zigbee-herdsman:adapter:ezsp:ezsp ==> {"_cls_":"nop","_id_":5,"_isRequest_":true}
2022-09-26T15:30:57.092Z zigbee-herdsman:adapter:ezsp:uart --> DATA (2,5,0): 6200010500
2022-09-26T15:30:57.092Z zigbee-herdsman:adapter:ezsp:uart --> [252021a9512aaafc7e]
2022-09-26T15:30:57.092Z zigbee-herdsman:adapter:ezsp:uart -?- waiting (3)
2022-09-26T15:30:57.096Z zigbee-herdsman:adapter:ezsp:uart <-- [5320a1a9512abfb97e]
2022-09-26T15:30:57.096Z zigbee-herdsman:adapter:ezsp:uart <-- DATA (5,3,0): 5320a1a9512abfb97e
2022-09-26T15:30:57.097Z zigbee-herdsman:adapter:ezsp:uart --> ACK  (6)
2022-09-26T15:30:57.097Z zigbee-herdsman:adapter:ezsp:uart --> [8610be7e]
2022-09-26T15:30:57.097Z zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 6280010500
2022-09-26T15:30:57.097Z zigbee-herdsman:adapter:ezsp:ezsp <== 0x5: {"_id_":5,"_cls_":"nop","_isRequest_":false}
2022-09-26T15:30:57.097Z zigbee-herdsman:adapter:ezsp:uart -+- waiting (3) success
2022-09-26T15:30:58.435Z zigbee-herdsman:adapter:ezsp:uart <-- [6320b1a9702ae2cb24d2fb7d5d946d53ed9d4e27abf4447e]
2022-09-26T15:30:58.435Z zigbee-herdsman:adapter:ezsp:uart <-- DATA (6,3,0): 6320b1a9702ae2cb24d2fb7d946d53ed9d4e27abf4447e00
2022-09-26T15:30:58.435Z zigbee-herdsman:adapter:ezsp:uart --> ACK  (7)
2022-09-26T15:30:58.435Z zigbee-herdsman:adapter:ezsp:uart --> [87009f7e]
2022-09-26T15:30:58.435Z zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 6290012400f7797d46b1583e38c1a40100000019
2022-09-26T15:30:58.435Z zigbee-herdsman:adapter:ezsp:ezsp <== 0x24: {"_id_":36,"_cls_":"trustCenterJoinHandler","_isRequest_":false,"newNodeId":31223,"newNodeEui64":[164,193,56,62,88,177,70,125],"status":1,"policyDecision":0,"parentOfNewNodeId":0}
kirovilya commented 2 years ago

@samuelthng are you using the latest dev version of z2m? can you attach the full herdsman log with attempts to connect the device? maybe you can still make a sniff of this whole process?

infabo commented 2 years ago

I experienced the same pairing issues with an IKEA shortcut button. While that button was pairing super-butter-smooth with home-assistant ZHA, it is one of the super-duper-troublesomest devices to pair at zigbee2mqtt.

It starts pairing and after about a minute a pairing failed message is logged.

So I now discovered these github issues and I am now using latest-dev docker image. Now I do not even see/get a "starting interview" message anymore. Nothing happens. So current dev seems to be non-working regarding EZSP adapters.

infabo commented 2 years ago

Not sure if it's related to the pairing issue but wanted to get some opinions and eyes on this. https://github.com/Koenkk/zigbee-herdsman/blame/85c277f82204be6d7419df396896645da549def6/src/adapter/ezsp/driver/driver.ts#L298

Seems to be related to my "this does nothing"-observation 🤣

samuelthng commented 2 years ago

@samuelthng are you using the latest dev version of z2m? can you attach the full herdsman log with attempts to connect the device? maybe you can still make a sniff of this whole process?

Yes using latest version, I'll try to create the log and sniff. My network is pretty noisy so not sure how to filter out the unrequired data. Will target to do so this weekend due to schedule.

samuelthng commented 2 years ago

Hey @kirovilya, sadly I don't think I'll be able to provide a sniff without an extended downtime on my setup. I've ordered a conbee and it's on it's way to replace my ezsp hub. Once that arrives I'll do the sniff.

Element2 commented 2 years ago

The latest dev modifications (Update Herdsman to 0.14.61) fixed the problem for me. The dev now pairs and interviews successful. And after a forced remove again pairs and interviews successful.

infabo commented 2 years ago

I can confirm. Most recent latest-dev docker image resolves the issue for me. IKEA shortcut button successfully pairing now (and again).

TTR6214 commented 2 years ago

I also confirm, now I'm able to pair again device when I use the last Zigbee2MQTT Edge in Home Assistant.

samuelthng commented 2 years ago

Confirmed as well, all previously removed devices now pairing properly. Thank you for fixing this kirovilya and koenkk. Not tagging because don't wanna ping needlessly.

tomm1ed commented 2 years ago

OMG awesome guys. Sorry for not getting back earlier but on build 1.27.2-dev commit: b54e299 the Tradfri plug now also works :)

tomm1ed commented 2 years ago

As this is fixed many thanks to @Koenkk and @kirovilya for taking the time to respond and fix the issue