search

Koenkk / zigbee2mqtt

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

Failed to find device #1334

Closed Bruceforce closed 5 years ago

Bruceforce commented 5 years ago

Hi,

today morning suddenly all my devices became unavailable. I updated my CC2531 to the latest "max stability" firmware to increase stability. I had to re-pair some of the devices (mainly ikea outlets) since they wouldn't automatically connect to the coordinator.

A few hours later I paired an Aqara switch and all devices are again unavailable.

The log says

zigbee2mqtt@1.2.1 start /app
node index.js
zigbee2mqtt:info 3/27/2019, 7:28:49 PM Logging to directory: '/app/data/log/2019-03-27.19-28-49'
zigbee2mqtt:error 3/27/2019, 7:40:04 PM Failed to find device with ieeAddr: '....'
...

Sometimes it will also log Message without device!

for all devices on max stability and default firmware. I'm using the latest dev docker image btw.

Edit: Today the same thing happened to the Ikea outlets again. The other devices stayed connected. Seems to be related to #1099

Koenkk commented 5 years ago

Can you share your database.db file?

Bruceforce commented 5 years ago

Yes. https://gist.github.com/Bruceforce/4833285cb6d20bf9a2041e20fc6654ca

Note: I have tried to re-pair the devices, but gave up on one of the Ikea outlets since it's hard to reach physically.

So this one here is still failing

zigbee2mqtt       |   zigbee2mqtt:debug 3/28/2019, 5:08:20 PM Received MQTT message on 'zigbee2mqtt/tradfri_switch_01/set' with data 'OFF'
zigbee2mqtt       |   zigbee2mqtt:error 3/28/2019, 5:08:20 PM Failed to find device with ieeAddr: '0x000d6ffffedd8d32'
zigbee2mqtt       |   zigbee2mqtt:info 3/28/2019, 5:08:20 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"entity_not_found","message":"0x000d6ffffedd8d32"}'

Edit: I also noticed that my Tradfri LEDs are no longer shown as unavailable if I power them off via wall switch despite I have set availability_timeout: 60

Koenkk commented 5 years ago

Devices are somehow missing from your database.db, e.g.0x000d6ffffedd8d32 is not in the database.db, can you try to re-pair these devices.

Bruceforce commented 5 years ago

@Koenkk I changed the channel yesterday to 25 - so I had to re-pair all devices. The same issue happened again after a few hours.

zigbee2mqtt       |   zigbee2mqtt:error 3/29/2019, 6:14:27 AM Failed to find device with ieeAddr: '0xd0cf5efffed828c3'
zigbee2mqtt       |   zigbee2mqtt:error 3/29/2019, 6:14:27 AM Failed to find device with ieeAddr: '0x90fd9ffffe32015e'
zigbee2mqtt       |   zigbee2mqtt:error 3/29/2019, 6:14:27 AM Failed to find device with ieeAddr: '0x000b57fffe30065f'

Here is my new database https://gist.github.com/Bruceforce/128b838186b7db7aa6eabc3c74a6a615 This time the failing devices are in there.

Koenkk commented 5 years ago

Yes, but as you see they are marked as deleted by {"$$deleted":true,"_id":"TzDJDMozsj0jRDlH"}. Did you use the new ban functionality or remove any devices through http://www.zigbee2mqtt.io/information/mqtt_topics_and_message_structure.html#zigbee2mqttbridgeconfigremove ?

Bruceforce commented 5 years ago

@Koenkk I'm not using ban function.

This is really strange. I did indeed remove ONE device 0x000b57fffe15051e but that isn't even listed as deleted. Maybe mosquitto is doing something strange?

Or do you have anything else in mind what could be causing this?

Koenkk commented 5 years ago

I think it's a bug in the dev branch, we need to figure out how to reproduce this.

Btje1977 commented 5 years ago

How did you remove them, I removed devices trough the HomeAssistant interface so not via mqtt message. I also deleted the latest dev branch and reinstalled everything. I also deleted everything in the share dir. I would think everything is clean then but when I want to add a device it doesn't recognize it.

zigbee2mqtt:info 3/27/2019, 9:38:51 PM New device 'undefined' with address 0x90fd9ffffe2a2de4 connected! zigbee2mqtt:debug 3/27/2019, 9:38:51 PM Saving state to file /share/zigbee2mqtt/state.json zigbee2mqtt:info 3/27/2019, 9:38:51 PM MQTT publish: topic 'homeassistant/bridge/log', payload '{"type":"device_connected","message":"0x90fd9ffffe2a2de4","meta":{}}' zigbee2mqtt:warn 3/27/2019, 9:38:51 PM Device with modelID 'undefined' is not supported. zigbee2mqtt:warn 3/27/2019, 9:38:51 PM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html zigbee2mqtt:warn 3/27/2019, 9:38:51 PM Device with modelID 'undefined' is not supported.

Bruceforce commented 5 years ago

I removed them via mqtt message (once per home assistant and in another try via a Windows client).

Koenkk commented 5 years ago

@Btje1977 for this device, the pairing procedure has not been completed, you should restart zigbee2mqtt, remove all entries of 0x90fd9ffffe2a2de4 from database.db and pair it again.

Koenkk commented 5 years ago

@Bruceforce can you provide the complete debug loggin? (log_level: debug) http://www.zigbee2mqtt.io/configuration/configuration.html

Btje1977 commented 5 years ago

@Btje1977 for this device, the pairing procedure has not been completed, you should restart zigbee2mqtt, remove all entries of 0x90fd9ffffe2a2de4 from database.db and pair it again.

Could it be that HA puts things back in the database. I see 4 devices already installed even when I remove and reinstall zigbee2mqtt

Koenkk commented 5 years ago

@Btje1977 it automatically add them if the devices rejoin.

Koenkk commented 5 years ago

I've probably found the issue, please update to the latest dev branch and re-pair any uncontrollable devices.

Bruceforce commented 5 years ago

@Koenkk I just collected logs with the old version. I'll upload it in case it would be useful (Logs1.zip - the last ones are the failing ones)

I updated the docker image and I'll let debug logging enabled and check if devices are still connected tomorrow. However since I re-paired all devices some of them no longer shows as unavailable in home assistant, even if I cut the power (for example the ikea outlets). In the logs it looks like Zigbee2mqtt is not pinging some devices anymore.

I just updated the docker image but now I can't pair any device at all. I tried re-plugging the stick, pressing the button on the stick and restarting zigbee2mqtt several times (see Logs2.zip)

Koenkk commented 5 years ago

Are the unavailable devices in the startup log?

3/29/2019, 10:25:53 PM - info: Currently 7 devices are joined:
3/29/2019, 10:25:53 PM - info: stairs_light (0x000b57fffe30065f): LED1623G12 - IKEA TRADFRI LED bulb E27 1000 lumen, dimmable, opal white (Router)
3/29/2019, 10:25:53 PM - info: living_room_ceiling_mid_light (0x90fd9ffffe32015e): LED1650R5 - IKEA TRADFRI LED bulb GU10 400 lumen, dimmable (Router)
3/29/2019, 10:25:53 PM - info: living_room_ceiling_right_light (0xd0cf5efffe72bffc): LED1650R5 - IKEA TRADFRI LED bulb GU10 400 lumen, dimmable (Router)
3/29/2019, 10:25:53 PM - info: living_room_ceiling_left_light (0xd0cf5efffed828c3): LED1650R5 - IKEA TRADFRI LED bulb GU10 400 lumen, dimmable (Router)
3/29/2019, 10:25:53 PM - info: tradfri_switch_02 (0x000d6ffffe9c414a): E1603 - IKEA TRADFRI control outlet (Router)
3/29/2019, 10:25:53 PM - info: mija_switch_01 (0x00158d0002e27365): WXKG01LM - Xiaomi MiJia wireless switch (EndDevice)
3/29/2019, 10:25:53 PM - info: tradfri_dimmer_01 (0x000b57fffe15051e): ICTC-G-1 - IKEA TRADFRI wireless dimmer (EndDevice)
Bruceforce commented 5 years ago

@Koenkk The devices seem to stay connected now and I also can control them - so the original issue seems to be solved. At least I haven't seen any more Failed to find device errors.

However since I re-paired everything the availability_timeout is not working anymore. My advanced settings looks like this:

advanced:
  panid: 6754
  channel: 25
  network_key: ...
  log_level: debug
  report: true
  availability_timeout: 60

Before the re-pairing all devices showed as unavailable in home assistant when they weren't connected to a power source. So when I cut the power of the tradfri bulbs they switched state to unavailable but now nothing happens and they always show the last state before I cut the power.

In the following log I started zigbee2mqtt with all 4 tradfri bulbs turned on. After 5 minutes I cut the power of all 4 bulbs and the state didn't switch to unavailable.

https://gist.github.com/Bruceforce/b3ca8571dc7b6033e3e896ad9ee3d07d

I noticed from the logs that only 0x000d6ffffe9c414a is being pinged regularly. Should I open a new issue for this?

I already tried to re-pair the devices again but it didn't help.

Koenkk commented 5 years ago

@Bruceforce can you share your data/database.db and configuration.yaml?

Bruceforce commented 5 years ago

database: https://gist.github.com/Bruceforce/59451879ec7cfdc7e9454007da41515b

configuration: https://gist.github.com/Bruceforce/440fc653f2250e86f642cb90724f667f

Koenkk commented 5 years ago

Can you set log_level: debug and provide the logs again.

As the original problem has been solved, let's continue further here: #775