search

sabeechen / hassio-google-drive-backup

Automatically create and sync Home Assistant backups into Google Drive
MIT License
3.14k stars 193 forks source link

History of sensors no longer updating after backup #957

Open silviudc opened 10 months ago

silviudc commented 10 months ago

Having a weird issue with this add-on, I have it set to do daily backups to google drive and some days after the backup is done, none of my sensors are recording their states, I have to restart HA to get them working again.

Can be seen last night, the straight line, and then recovered after HA restart: image

add-on version: 0.112.1 HA: image

Nothing useful in the logs: 12-09 20:00:00 INFO Syncing Backups 12-09 20:00:00 INFO Requesting a new backup 12-09 21:08:47 INFO A backup directory file was modified, we'll check for new backups soon. 12-09 21:12:27 INFO A backup directory file was modified, we'll check for new backups soon. 12-09 21:12:27 INFO Backup finished 12-09 21:12:27 INFO Syncing Backups 12-09 21:12:29 INFO Deleting 'Full Backup 2023-12-02 20:00:00' from Home Assistant 12-09 21:12:29 INFO Uploading 'Full Backup 2023-12-09 20:00:00' to Google Drive 12-09 21:16:23 INFO Deleting 'Full Backup 2023-12-05 20:00:00' From Google Drive 12-09 21:16:24 INFO Syncing Backups 12-09 21:19:28 INFO A backup directory file was modified, we'll check for new backups soon. 12-09 22:47:09 INFO Syncing Backups 12-10 00:41:57 INFO Syncing Backups 12-10 03:39:50 INFO Syncing Backups 12-10 05:13:57 INFO Syncing Backups 12-10 07:06:54 INFO Syncing Backups 12-10 08:41:07 INFO Syncing Backups 12-10 10:18:48 INFO Syncing Backups

And not seeing any errors in HA logs either around that time. The backups are around 1GB in size

sabeechen commented 10 months ago

A couple things come to mind:

If there is somethign wrong with your database, that'll usually show up in 1 of two places:

  1. The Home Assistant Logs: "Settings" > "System > "Logs"
  2. The Supervisor logs. These are in the same place, but you need to fiddle with some Hoem Assistant settings to make it visible. See this FAQ item for how to get there.
silviudc commented 10 months ago

Yes using MariaDB and I'm not turning anything off while doing the backups but this add-on must be doing that to the DB while the backup is running right? Just seems to not be able to turn it back on after the backup is done (sometimes) Is there a method I could force the DB to come back online via an automation perhaps? Nothing out of the ordinary in either log

sabeechen commented 10 months ago

This addon can be configured to stop addons while backing up, though I don't recommend it. Just make sure you don't have the "Stop Addons" section enabled in your addon settings. If MariaDB is left running during a backup (which is normal) HA will put it into a state that buffers writes to the database while the backup is in progress. I suspect that something goes wrong after the backup when HA brings it out of that state. Can you check what MariaDB's logs look like after a backup finishes?

silviudc commented 10 months ago

So this was last night logs (or maybe multiple days but cannot see the dates) where everything worked fine and the issue did not happen:

s6-rc: info: service mariadb-lock-core: starting
[20:00:06] INFO: Start MariaDB client (to lock tables for backups)
s6-rc: info: service mariadb-lock-core successfully started
s6-rc: info: service mariadb-lock-post: starting
[20:00:06] INFO: MariaDB tables locked
s6-rc: info: service mariadb-lock-post successfully started
s6-rc: info: service mariadb-lock-post: stopping
[20:58:56] INFO: MariaDB tables unlocked
s6-rc: info: service mariadb-lock-post successfully stopped
s6-rc: info: service mariadb-lock-core: stopping
[20:58:56] INFO: MariaDB client (to lock tables for backups) stopped
s6-rc: info: service mariadb-lock-core successfully stopped
s6-rc: info: service mariadb-lock-core: starting
[20:00:06] INFO: Start MariaDB client (to lock tables for backups)
s6-rc: info: service mariadb-lock-core successfully started
s6-rc: info: service mariadb-lock-post: starting
[20:00:06] INFO: MariaDB tables locked
s6-rc: info: service mariadb-lock-post successfully started
s6-rc: info: service mariadb-lock-post: stopping
[21:08:23] INFO: MariaDB tables unlocked
s6-rc: info: service mariadb-lock-post successfully stopped
s6-rc: info: service mariadb-lock-core: stopping
[21:08:23] INFO: MariaDB client (to lock tables for backups) stopped
s6-rc: info: service mariadb-lock-core successfully stopped
s6-rc: info: service mariadb-lock-core: starting
[20:00:06] INFO: Start MariaDB client (to lock tables for backups)
s6-rc: info: service mariadb-lock-core successfully started
s6-rc: info: service mariadb-lock-post: starting
[20:00:06] INFO: MariaDB tables locked
s6-rc: info: service mariadb-lock-post successfully started
s6-rc: info: service mariadb-lock-post: stopping
[20:51:26] INFO: MariaDB tables unlocked
s6-rc: info: service mariadb-lock-post successfully stopped
s6-rc: info: service mariadb-lock-core: stopping
[20:51:27] INFO: MariaDB client (to lock tables for backups) stopped
s6-rc: info: service mariadb-lock-core successfully stopped
s6-rc: info: service mariadb-lock-core: starting
[20:00:06] INFO: Start MariaDB client (to lock tables for backups)
s6-rc: info: service mariadb-lock-core successfully started
s6-rc: info: service mariadb-lock-post: starting
[20:00:06] INFO: MariaDB tables locked
s6-rc: info: service mariadb-lock-post successfully started
s6-rc: info: service mariadb-lock-post: stopping
[20:52:37] INFO: MariaDB tables unlocked
s6-rc: info: service mariadb-lock-post successfully stopped
s6-rc: info: service mariadb-lock-core: stopping
[20:52:37] INFO: MariaDB client (to lock tables for backups) stopped
s6-rc: info: service mariadb-lock-core successfully stopped
s6-rc: info: service mariadb-lock-core: starting
[20:00:05] INFO: Start MariaDB client (to lock tables for backups)
s6-rc: info: service mariadb-lock-core successfully started
s6-rc: info: service mariadb-lock-post: starting
[20:00:05] INFO: MariaDB tables locked
s6-rc: info: service mariadb-lock-post successfully started
s6-rc: info: service mariadb-lock-post: stopping
[20:56:21] INFO: MariaDB tables unlocked
s6-rc: info: service mariadb-lock-post successfully stopped
s6-rc: info: service mariadb-lock-core: stopping
[20:56:21] INFO: MariaDB client (to lock tables for backups) stopped
s6-rc: info: service mariadb-lock-core successfully stopped

Will keep an eye out tonight as it might happen

silviudc commented 10 months ago

Did it again today, nothing out of the ordinary in the mariaDB logs

s6-rc: info: service mariadb-lock-core: starting
[20:00:06] INFO: Start MariaDB client (to lock tables for backups)
s6-rc: info: service mariadb-lock-core successfully started
s6-rc: info: service mariadb-lock-post: starting
[20:00:06] INFO: MariaDB tables locked
s6-rc: info: service mariadb-lock-post successfully started
s6-rc: info: service mariadb-lock-post: stopping
[20:58:46] INFO: MariaDB tables unlocked
s6-rc: info: service mariadb-lock-post successfully stopped
s6-rc: info: service mariadb-lock-core: stopping
[20:58:46] INFO: MariaDB client (to lock tables for backups) stopped
s6-rc: info: service mariadb-lock-core successfully stopped
s6-rc: info: service mariadb-lock-core: starting
[20:00:05] INFO: Start MariaDB client (to lock tables for backups)
s6-rc: info: service mariadb-lock-core successfully started
s6-rc: info: service mariadb-lock-post: starting
[20:00:06] INFO: MariaDB tables locked
s6-rc: info: service mariadb-lock-post successfully started
s6-rc: info: service mariadb-lock-post: stopping
[20:57:31] INFO: MariaDB tables unlocked
s6-rc: info: service mariadb-lock-post successfully stopped
s6-rc: info: service mariadb-lock-core: stopping
[20:57:31] INFO: MariaDB client (to lock tables for backups) stopped
s6-rc: info: service mariadb-lock-core successfully stopped

And this is the HA logs:

2023-12-17 20:35:29.243 ERROR (MainThread) [homeassistant.components.recorder.core] The recorder backlog queue reached the maximum size of 70918 events; usually, the system is CPU bound, I/O bound, or the database is corrupt due to a disk problem; The recorder will stop recording events to avoid running out of memory

Which coincides with when it stops logging. I have have this integration from my PV inverter which sends data at 2 second intervals, for multiple sensors, so I wonder if the queue gets backed up. The updates usually take 40 mins or so, but then again it only does it sometimes

sabeechen commented 10 months ago

Well thats interesting. It looks like if the recorder backlog gets too high it just gives up forever. I'd expect it to be a little more clever if it can tell the backlog is high because the database is being backed up. This might be worth creating an issue in Home Assistant, from the looks of it this isn't a problem specific to this addon and would affect anyone with a setup like yours even if they backup through Home Assistant's UI.

It doesn't look like HA's recorder lets you configure the size of the backlog. I'm not sure of a good solution for this but some thoughts are:

But none of them are good solutions. I'd consider this a bug in HA, though I can't say if the HA devs would also see it that way.

silviudc commented 10 months ago

I agree, now that I have seen that error on the HA log I think this is just HA behaviour and not really this add-on so I will create an issue there with the same. I have recorder set to save 7 days so in my mind that's not that high. These sensors are important so not logging them at all is not really an option, need to look into their update intervals. I tried calling recorder.enable when it was "stopped" and it did not recover, had to reboot HA Maybe hardware is limitation, it's a 2GB rpi4 with SATA SSD, hoping can upgrade to something with nvme and maybe then it will backup quicker?