search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.88k stars 30.95k forks source link

AVM FRITZ!SmartHome randomly resets itself #121059

Open Momentum6890 opened 4 months ago

Momentum6890 commented 4 months ago

The problem

The FRITZ! SmartHome integration resets itself from time to time (again today and for the last time about 8 weeks ago) as if i had "reinstalled" it. There is no time "trigger", it happens randomly and without any reason. Unfortunately, i can't say exactly when it started. This is very annoying because it also resets all changes (ID, name) and then the associated automations no longer work.

Unfortunately, there is no way to understand why or what triggers this. There is absolutely nothing in the logs about it.

What version of Home Assistant Core has the issue?

core-2024.6.4

What was the last working version of Home Assistant Core?

core-2024.3.0

What type of installation are you running?

Home Assistant OS

Integration causing the issue

AVM FRITZ!SmartHome

Link to integration documentation on our website

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

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 4 months ago

Hey there @mib1185, @flabbamann, mind taking a look at this issue as it has been labeled with an integration (fritzbox) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `fritzbox` 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 fritzbox` 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)

fritzbox documentation fritzbox source (message by IssueLinks)

mib1185 commented 4 months ago

What exactly do you mean with "rest itself" and "as if i had reinstalled it" ?

Momentum6890 commented 4 months ago

What exactly do you mean with "rest itself" and "as if i had reinstalled it" ?

@mib1185 Von Zeit zu Zeit setzt sich die Integration ohne ersichtlichen Grund selbst zurück, so als würde ich die Integration löschen und wieder neu hinzufügen (habe ich aber nicht) und dadurch sind dann natürlich auch alle Einstellungen (Namen, IDs, Bereiche) weg.

Mir fällt das dann nur dadurch auf, weil meine Temperatur- und Luftfeuchtigkeitssensoren nicht mehr verfügbar sind und Automationen nicht funktionieren. Die Logs geben auch nichts her :/

mib1185 commented 4 months ago

Hi @Momentum6890

as a first step, please download and provide the diagnostics data for this integration.

Note: it is better to drag the log into the comment (which will add it as an attachment) and not copy paste as it is hard to read logs in GitHub.

thx 👍

Momentum6890 commented 4 months ago

Hi @mib1185

here is the file:

config_entry-fritzbox-f943d454692a4395a4ef3e89bf7efc7e.json

mib1185 commented 4 months ago

There is nothing suspicious in this diagnostic data - so, as discussed on Facebook, we need to wait for next occurrence and hope that the enabled debug log will deliver helpful information

Momentum6890 commented 4 months ago

Yes, we hope the best 🙏 😅

Momentum6890 commented 2 months ago

@mib1185 it took a while, but tonight at 05:05 it happened again. FRITZ!SmartHome reset the entities of all devices, as if I had deleted the integration and added it again, which I didn't do. I was asleep at that time xD

home-assistant2024-09-0705-15.log

home-assistant2024-09-0805-15.log <- before nightly restart: I found something in this log on 08.09.2024 at 05:02. "FRITZ!SmartHome removing no more existing device" and "Removing obsolete entity entry". That can't be, my FRITZ!Box goes off at 04:55 and starts again at 05:00 (nightly restart). But the integration must not simply delete and recreate the entities by itself just because the devices are not all available again due to the restart.

home-assistant_fritzbox_2024-09-08T09-04-51.958Z.log <- after nightly restart: debug “deactivated” at 11:00 a.m.

mib1185 commented 2 months ago 
2024-09-08 05:02:02.972 INFO (SyncWorker_54) [pyfritzhome.fritzhome] Updating Devices ...
2024-09-08 05:02:03.580 INFO (SyncWorker_54) [pyfritzhome.fritzhome] sid:0000000000000000, challenge:2$60000$c999ac1ea6b56e6e6a15e52bbed29689$6000$e7a5cf61a96c99a04adb54515b92793d, blocktime:0
2024-09-08 05:02:04.350 INFO (SyncWorker_54) [pyfritzhome.fritzhome] Updating Devices ...
2024-09-08 05:02:06.863 INFO (SyncWorker_54) [pyfritzhome.fritzhome] Removing no more existing device 08761 0338583
2024-09-08 05:02:06.864 INFO (SyncWorker_54) [pyfritzhome.fritzhome] Removing no more existing device 08761 0265744
2024-09-08 05:02:06.864 INFO (SyncWorker_54) [pyfritzhome.fritzhome] Removing no more existing device 09995 0963068
2024-09-08 05:02:06.864 INFO (SyncWorker_54) [pyfritzhome.fritzhome] Removing no more existing device 09995 0963170
2024-09-08 05:02:06.864 INFO (SyncWorker_54) [pyfritzhome.fritzhome] Removing no more existing device 15282 0085356
2024-09-08 05:02:06.864 INFO (SyncWorker_54) [pyfritzhome.fritzhome] Removing no more existing device 09995 0963946
2024-09-08 05:02:06.864 INFO (SyncWorker_54) [pyfritzhome.fritzhome] Updating Templates ...

The issue was caused by mistake by the new automatic cleanup (added with https://github.com/hthiery/python-fritzhome/pull/99). It seems that your Fritzbox already accepted a new connection from HA, even it was not fully up and running after the restart and those did not properly report the smarthome devices (at 05:04:37.081 all smarthome devices are reported correct for the first time after the restart of the Fritzbox)

unfortunately there was no debug enabled for the pyfritzhome library :slightly_frowning_face: How exactly did you enable the debug logging? Best way to do so (to be on safe side even after HA reboots) is to add the following to your configuration.yaml:

logger:
  default: info
  logs:
    homeassistant.components.fritzbox: debug
    pyfritzhome: debug
Momentum6890 commented 2 months ago

Ah ok, that narrows down the cause. Too bad, i only activated the debug for fritzbox in configuration.yaml. Sorry, i didn't know that i also had to activate it for pyfritzhome 😅 I've done that now. Now we have to wait again 😅

Momentum6890 commented 1 week ago

@mib1185 after a long wait, it happened again tonight (12.11.2024, approx 05:00 a.m.). To be on the safe side, here are the last 4 saved logs: home-assistant2024-11-1115-34.log home-assistant2024-11-1117-15.log home-assistant2024-11-1205-15.log home-assistant2024-11-1207-20.log

mib1185 commented 1 week ago

2024-11-12 04:55:15.599 last successful data fetch from your fritzbox

2024-11-12 04:55:15.599 DEBUG (MainThread) [homeassistant.components.fritzbox] Finished fetching 01J246HGPAR1MZJVYTR8GVZ6JC data in 0.202 seconds (success: True)

2024-11-12 04:55:55.291 first unsuccessful data fetch

2024-11-12 04:55:55.291 ERROR (MainThread) [homeassistant.components.fritzbox] Error fetching 01J246HGPAR1MZJVYTR8GVZ6JC data: 
2024-11-12 04:55:55.292 DEBUG (MainThread) [homeassistant.components.fritzbox] Finished fetching 01J246HGPAR1MZJVYTR8GVZ6JC data in 10.016 seconds (success: False)

2024-11-12 05:02:02.276 your fritzbox is reachable again, but a new session id (sid) was created, so the fritzbox has definitively rebootet

2024-11-12 05:02:02.276 INFO (SyncWorker_60) [pyfritzhome.fritzhome] Updating Devices ...
2024-11-12 05:02:02.277 DEBUG (SyncWorker_60) [pyfritzhome.fritzhome] self._sid:0b714ab7fbfec39a
2024-11-12 05:02:02.835 INFO (SyncWorker_60) [pyfritzhome.fritzhome] sid:0000000000000000, challenge:2$60000$da7be0add1716237048e10ecda74fe85$6000$9ac3af684d66443e3a24dcfcac2340b6, blocktime:0
2024-11-12 05:02:03.506 INFO (SyncWorker_60) [pyfritzhome.fritzhome] Updating Devices ...
2024-11-12 05:02:03.506 DEBUG (SyncWorker_60) [pyfritzhome.fritzhome] self._sid:349920ea1d996c1e

2024-11-12 05:02:03.733 the fritzbox responded with empty devicelist and templatelist so all entities in HA gets removed

2024-11-12 05:02:03.733 DEBUG (SyncWorker_60) [pyfritzhome.fritzhome] <Element 'devicelist' at 0x7fd6ebd1e2a0>
2024-11-12 05:02:03.733 INFO (SyncWorker_60) [pyfritzhome.fritzhome] Removing no more existing device 08761 0338583
2024-11-12 05:02:03.734 INFO (SyncWorker_60) [pyfritzhome.fritzhome] Removing no more existing device 08761 0265744
2024-11-12 05:02:03.734 INFO (SyncWorker_60) [pyfritzhome.fritzhome] Removing no more existing device 09995 0963068
2024-11-12 05:02:03.734 INFO (SyncWorker_60) [pyfritzhome.fritzhome] Removing no more existing device 09995 0963170
2024-11-12 05:02:03.734 INFO (SyncWorker_60) [pyfritzhome.fritzhome] Removing no more existing device 15282 0085356
2024-11-12 05:02:03.734 INFO (SyncWorker_60) [pyfritzhome.fritzhome] Removing no more existing device 09995 0963946
2024-11-12 05:02:03.734 INFO (SyncWorker_60) [pyfritzhome.fritzhome] Updating Templates ...
2024-11-12 05:02:03.734 DEBUG (SyncWorker_60) [pyfritzhome.fritzhome] self._sid:349920ea1d996c1e
2024-11-12 05:02:03.835 DEBUG (SyncWorker_60) [pyfritzhome.fritzhome] <Element 'templatelist' at 0x7fd712f3dd50>

2024-11-12 05:02:33.276 the fritzbox responded with incomplete data

2024-11-12 05:02:33.276 INFO (SyncWorker_38) [pyfritzhome.fritzhome] Updating Devices ...
2024-11-12 05:02:33.276 DEBUG (SyncWorker_38) [pyfritzhome.fritzhome] self._sid:349920ea1d996c1e
2024-11-12 05:02:33.384 DEBUG (SyncWorker_38) [pyfritzhome.fritzhome] <Element 'devicelist' at 0x7fd6ccceb420>
2024-11-12 05:02:33.384 INFO (SyncWorker_38) [pyfritzhome.fritzhome] Adding new Device 08761 0338583
2024-11-12 05:02:33.384 DEBUG (SyncWorker_38) [pyfritzhome.devicetypes.fritzhomedevicebase] update base device
2024-11-12 05:02:33.385 DEBUG (SyncWorker_38) [pyfritzhome.devicetypes.fritzhomeentitybase] b'<device identifier="08761 0338583" id="16" functionbitmask="35712" fwversion="04.26" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Stecker: FRITZ!Box</name><switch><state>1</state><mode>auto</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>235486</voltage><power>14010</power><energy>301010</energy></powermeter><temperature><celsius>290</celsius><offset>0</offset></temperature></device>'
2024-11-12 05:02:33.386 DEBUG (SyncWorker_38) [pyfritzhome.devicetypes.fritzhomedevicetemperature] update temperature device
2024-11-12 05:02:33.386 DEBUG (SyncWorker_38) [pyfritzhome.devicetypes.fritzhomedeviceswitch] update switch device
2024-11-12 05:02:33.386 DEBUG (SyncWorker_38) [pyfritzhome.devicetypes.fritzhomedevicepowermeter] update powermeter device
2024-11-12 05:02:33.386 INFO (SyncWorker_38) [pyfritzhome.fritzhome] Adding new Device 08761 0265744
2024-11-12 05:02:33.386 DEBUG (SyncWorker_38) [pyfritzhome.devicetypes.fritzhomedevicebase] update base device
2024-11-12 05:02:33.387 DEBUG (SyncWorker_38) [pyfritzhome.devicetypes.fritzhomeentitybase] b'<device identifier="08761 0265744" id="17" functionbitmask="35712" fwversion="04.26" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>Stecker: Home Assistant</name><switch><state>1</state><mode>auto</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage /><power /><energy /></powermeter><temperature><celsius>300</celsius><offset>0</offset></temperature></device>'
2024-11-12 05:02:33.387 DEBUG (SyncWorker_38) [pyfritzhome.devicetypes.fritzhomedevicetemperature] update temperature device
2024-11-12 05:02:33.387 DEBUG (SyncWorker_38) [pyfritzhome.devicetypes.fritzhomedeviceswitch] update switch device
2024-11-12 05:02:33.387 DEBUG (SyncWorker_38) [pyfritzhome.devicetypes.fritzhomedevicepowermeter] update powermeter device
2024-11-12 05:02:33.390 ERROR (MainThread) [homeassistant.components.fritzbox] Unexpected error fetching 01J246HGPAR1MZJVYTR8GVZ6JC data
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 382, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/fritzbox/coordinator.py", line 152, in _async_update_data
    new_data = await self.hass.async_add_executor_job(self._update_fritz_devices)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/fritzbox/coordinator.py", line 106, in _update_fritz_devices
    self.fritz.update_devices(ignore_removed=False)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/fritzhome.py", line 180, in update_devices
    device = FritzhomeDevice(self, node=element)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/fritzhomedevice.py", line 38, in __init__
    super().__init__(fritz, node)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/devicetypes/fritzhomeentitybase.py", line 28, in __init__
    self._update_from_node(node)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/fritzhomedevice.py", line 41, in _update_from_node
    super()._update_from_node(node)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/devicetypes/fritzhomedevicealarm.py", line 18, in _update_from_node
    super()._update_from_node(node)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/devicetypes/fritzhomedeviceblind.py", line 18, in _update_from_node
    super()._update_from_node(node)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/devicetypes/fritzhomedevicebutton.py", line 17, in _update_from_node
    super()._update_from_node(node)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/devicetypes/fritzhomedevicehumidity.py", line 18, in _update_from_node
    super()._update_from_node(node)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/devicetypes/fritzhomedevicelevel.py", line 19, in _update_from_node
    super()._update_from_node(node)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/devicetypes/fritzhomedevicelightbulb.py", line 25, in _update_from_node
    super()._update_from_node(node)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/devicetypes/fritzhomedevicepowermeter.py", line 26, in _update_from_node
    self._update_powermeter_from_node(node)
  File "/usr/local/lib/python3.12/site-packages/pyfritzhome/devicetypes/fritzhomedevicepowermeter.py", line 37, in _update_powermeter_from_node
    self.power = int(val.findtext("power"))
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^
ValueError: invalid literal for int() with base 10: ''

2024-11-12 05:04:33.470 first successful data fetch after fritzbox reboot, every entities are recreated

2024-11-12 05:04:33.470 DEBUG (MainThread) [homeassistant.components.fritzbox] Finished fetching 01J246HGPAR1MZJVYTR8GVZ6JC data in 0.194 seconds (success: True)
mib1185 commented 1 week ago

Why did your fritzbox reboot between 2024-11-12 04:55:15.599 and 2024-11-12 04:55:55.291 ?

I'll think about, how to mitigate these incomplete data response from the fritzbox after a reboot

Momentum6890 commented 1 week ago

@mib1185 i'm doing a nightly reboot here. I switch off the SmartPlug with an automation at 04:55 a.m. and switch it on again automatically at 05:00 a.m.. 5 minutes is also the recommended length from AVM so that the internal cache is emptied.

It would be great if this could be minimised a little so that restarts can be carried out safely :D

mib1185 commented 1 week ago

tbh. my Fritzbox has uptimes of upto multiple months without any issues. I only need to re-connect the ppp-session from time to time (i've disabled the automatic daily/nightly re-connect).

As mitigation on your end, I would recommend not to reboot your Fritzbox every night as long as no fix is available here.

mib1185 commented 1 week ago

on the other hand, if you know when your Fritzbox ist expected to be unavailable, just disable the integration in HA during this time frame via an automation

Momentum6890 commented 1 week ago

Unfortunately I can't deactivate the 24h disconnect on my FritzBox, so I do it manually so that it happens where it doesn't bother me.

Then I wait until a fix is available :)

How can I deactivate the integration? There is no action for it. Do I need Spook from Frenk for this?

mib1185 commented 1 week ago

Unfortunately I can't deactivate the 24h disconnect on my FritzBox, so I do it manually so that it happens where it doesn't bother me.

wait, you reboot the whole Fritzbox, just to achieve the re-connect?

How can I deactivate the integration? There is no action for it. Do I need Spook from Frenk for this?

you're right - it is an action provided by spook :see_no_evil:

Momentum6890 commented 1 week ago

Yes and no. I don't do it because I enjoy it :P I do it because I can't prevent the 24h disconnect/restart of my provider. That's why I do it myself, so that I can “determine” when it happens.

Ok, then I'll have to install Spook after all :P

flabbamann commented 1 week ago

Yes and no. I don't do it because I enjoy it :P I do it because I can't prevent the 24h disconnect/restart of my provider. That's why I do it myself, so that I can “determine” when it happens.

Ok, then I'll have to install Spook after all :P

You know the fritzbox has a setting to choose the time when the reconnect should happen, right? 😃

Momentum6890 commented 6 days ago

You know the fritzbox has a setting to choose the time when the reconnect should happen, right? 😃

Yes, with a “normal” FritzBox. I have a FritzBox 6690 Cable. Unfortunately, there is no “Connection settings” option here.

flabbamann commented 6 days ago

You know the fritzbox has a setting to choose the time when the reconnect should happen, right? 😃

Yes, with a “normal” FritzBox. I have a FritzBox 6690 Cable. Unfortunately, there is no “Connection settings” option here.

Interesting, I did not know that. Do you know why?

Momentum6890 commented 5 days ago

You know the fritzbox has a setting to choose the time when the reconnect should happen, right? 😃

Yes, with a “normal” FritzBox. I have a FritzBox 6690 Cable. Unfortunately, there is no “Connection settings” option here.

Interesting, I did not know that. Do you know why?

Because here the FRITZ!Box Cable receives the signal for a disconnect/restart from the cable network/from the provider server and cannot be influenced. But unfortunately I don't know why this is the case with cable. It's a bit different with DSL.

It is also not possible to make any "connection settings" with a cable FritzBox because the settings are sent directly from the server to the box and cannot be changed. For this purpose, the MAC address of the box is registered in the customer account and on the ISP server when logging in with a new box for the first time.

I don't know about fiber optics, unfortunately that won't happen for me until next year or the year after 😭 😂