Why do I have hourly copies of my .db???

[DrKK]

Does anyone know the answer to this:

My 9.3 main pool:

I have a whole slew of copies of my FreeNAS database, apparently automatically placed, one per hour, in my /var/db/system directory. At 330kB apiece, they add up to several MB. Not a show-stopper, but still, I don't want these, and I certainly don't want them HOURLY for Christ's sake.

Does anyone know the story behind these and what the deal is?

 

[cyberjock]

I don't appear to have any .db files in /var/db/system nor do I see any directories that would allude to there being databases there. Can you elaborate?

 

[DrKK]

I don't appear to have any .db files in /var/db/system nor do I see any directories that would allude to there being databases there. Can you elaborate?

I can certainly elaborate, sir:

Now what's interesting, is that you'll note that the hourly database backups seem to have STOPPED when I installed last night's system update.

And also if you look at the timestamps, they don't actually look hourly. I am not sure what the hell is going on?

Maybe you can ask Josh what this is?

 

[danb35]

I'm noticing something similar:

Code:

[root@freenas2] /var/db/system# ll -h
total 3439
drwxr-xr-x   6 root  wheel    39B Dec 31 09:13 ./
drwxr-xr-x  18 root  wheel   1.1k Dec 31 09:59 ../
drwxrwxr-x   2 root  wheel     7B Dec 21 15:33 cores/
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-10.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-11.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-12.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-13.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-14.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-15.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-16.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-17.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-18.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-19.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-20.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-21.db
-rw-r-----   1 root  wheel   315k Dec 28 22:49 freenas2.familybrown.org-2014-12-28-22.db
-rw-r-----   1 root  wheel   315k Dec 28 22:47 freenas2.familybrown.org-2014-12-28-9.db
-rw-r-----   1 root  wheel   315k Dec 30 13:17 freenas2.familybrown.org-2014-12-30-1.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-1.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-10.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-11.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-12.db
-rw-r-----   1 root  wheel   315k Dec 31 07:00 freenas2.familybrown.org-2014-12-31-13.db
-rw-r-----   1 root  wheel   315k Dec 31 07:01 freenas2.familybrown.org-2014-12-31-14.db
-rw-r-----   1 root  wheel   315k Dec 31 07:01 freenas2.familybrown.org-2014-12-31-15.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-2.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-3.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-4.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-5.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-6.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-7.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-8.db
-rw-r-----   1 root  wheel   315k Dec 31 06:58 freenas2.familybrown.org-2014-12-31-9.db
-rw-r--r--   1 root  wheel     0B Dec 21 15:31 nfs-stablerestart
-rw-r--r--   1 root  wheel     0B Dec 21 15:31 nfs-stablerestart.bak
-rw-r--r--   1 root  wheel   932B Sep 30 11:04 perftest.txz
drwxr-xr-x   3 root  wheel     4B Jun 15  2014 rrd-03dfc785c4b1491e8f0739ff94ed3f4b/
drwxr-xr-x   4 root  wheel    28B Dec 31 10:39 samba4/
drwxr-xr-x   3 root  wheel     3B Mar  9  2014 syslog-03dfc785c4b1491e8f0739ff94ed3f4b/
[root@freenas2] /var/db/system#

Looking at the timestamps, they clearly aren't hourly or anything close to it. There is one at 22:47 on 28 Dec, and 13 at 22:49 on 28 Dec. Then one at 13:17 on 30 Dec, then 12 at 06:58 today, one at 07:00, and two at 07:01. I installed the system update this morning a little before 8:00, but it's too soon to tell if that's had any effect.

It also looks like there were more backups from 28 Dec that were expired; the lowest number on that date is -9. Right now, there are 30 backups present, a suspiciously round number which further suggests to me that there's some mechanism expiring these backups.

 

[cyberjock]

I will ask a dev about this. I know that some copies of the database were to be put in the .system dataset (which is now mounted in /var/db). I've personally seen files there before, but strangely I'm not seeing any on my Mini right now. /shrug

 

[danb35]

I just did a scrub of my boot pool, which resulted in one of the USB sticks faulting, red flashing light in the GUI, emails to admin user, etc. At the same time, 13 dumps of the database were generated, all with the same 11:00 timestamp. Total number is still 30, so older backups are definitely being expired.

 

[Whattteva]

I observe the same things also. Here's mine:

Code:

-rw-r-----  1 root  wheel  313k Jan  1 14:57 freenas.local-2015-01-01-1.db
-rw-r-----  1 root  wheel  313k Jan  1 15:09 freenas.local-2015-01-01-10.db
-rw-r-----  1 root  wheel  313k Jan  1 15:10 freenas.local-2015-01-01-11.db
-rw-r-----  1 root  wheel  313k Jan  1 15:10 freenas.local-2015-01-01-12.db
-rw-r-----  1 root  wheel  313k Jan  1 15:19 freenas.local-2015-01-01-13.db
-rw-r-----  1 root  wheel  313k Jan  1 15:25 freenas.local-2015-01-01-14.db
-rw-r-----  1 root  wheel  313k Jan  1 15:47 freenas.local-2015-01-01-15.db
-rw-r-----  1 root  wheel  313k Jan  1 15:47 freenas.local-2015-01-01-16.db
-rw-r-----  1 root  wheel  313k Jan  1 15:47 freenas.local-2015-01-01-17.db
-rw-r-----  1 root  wheel  313k Jan  1 15:47 freenas.local-2015-01-01-18.db
-rw-r-----  1 root  wheel  313k Jan  1 17:02 freenas.local-2015-01-01-19.db
-rw-r-----  1 root  wheel  313k Jan  1 14:57 freenas.local-2015-01-01-2.db
-rw-r-----  1 root  wheel  313k Jan  1 14:57 freenas.local-2015-01-01-3.db
-rw-r-----  1 root  wheel  313k Jan  1 14:57 freenas.local-2015-01-01-4.db
-rw-r-----  1 root  wheel  313k Jan  1 14:57 freenas.local-2015-01-01-5.db
-rw-r-----  1 root  wheel  313k Jan  1 14:57 freenas.local-2015-01-01-6.db
-rw-r-----  1 root  wheel  313k Jan  1 15:09 freenas.local-2015-01-01-7.db
-rw-r-----  1 root  wheel  313k Jan  1 15:09 freenas.local-2015-01-01-8.db
-rw-r-----  1 root  wheel  313k Jan  1 15:09 freenas.local-2015-01-01-9.db

 

[Roger Wilco]

Hi,

I'd say (at least here it looks like this) that every time a db relevant configuration change is done a new file is written. E.g. stopping a service results in a new file (because the stopped service should remain stopped after a reboot, too).
On the other hand a permission change (on a dataset) does not result in a new file (because this is nothing which needs to be stored in the db).

Export two db files with a sqlite browser (e.g. sqlitestudio on OSX) to XML or something and diff the files...

 

[Roger Wilco]

Btw, do you think it's worth it to open a feature ticket because of the filenames?
The index (last number in front of the db suffix) should IMO always have the same number of digits - 01 (or 00001) instead of 1 makes sorting easier...

 

[kjp4756]

I'm seeing the same thing on my server. There was a db file created today in the afternoon and I haven't even logged on to the web gui for a week or more.

 

[Roger Wilco]

Nice :)
Since I've posted my previous message I have rebooted the box here 3 or 4 times (test installation) and, I also have 18 new files.
Seems like there was a 30 file limit. I don't have an answer to this...

 

[danb35]

Btw, do you think it's worth it to open a feature ticket because of the filenames?
The index (last number in front of the db suffix) should IMO always have the same number of digits - 01 (or 00001) instead of 1 makes sorting easier...

I'd agree that padding the index to two digits would be a good thing, but I think that's a much smaller issue than what's going on in the first place. I'm not sure it's a huge problem--the files are expired at 30, so this isn't going to take more than 10 MB or so of space, but it seems odd that (apparently) multiple backups of the config database are stored at the same time. For example, right now, I have 17 copies from 3 Jan. Of those, 14 are from between 17:16:05 and 17:16:08. At that time, the system was rebooting after installing an update. The first on that date is from 07:22, the second is from 14:19. At 14:19, I installed a new USB stick to mirror the boot device, but I don't see anything in the system logs for 7:22. The last is 17:17:02, just under a minute after the bulk of them.

Unfortunately, trying to export these to XML repeatably crashes SQLiteStudio 3.0.1 on my Mac, but I can export them to SQL. Diff between two of the 17:16 files shows no differences other than the header line ("File generated with SQLiteStudio v3.0.1 on Mon Jan 5 09:07:11 2015", of course the date/time will be different). Diff between the 07:22 file and the 14:19 file shows two lines dealing with the storage_disk table (understandable). Diff between one of the 17:16 files and the 17:17 file shows a bunch of differences (1421 lines per wc -l).

So, a change to configuration was made on 3 Jan at 14:19, and a copy of the database was saved. The system was rebooted at 17:16, and a bunch of apparently-identical copies were saved. The database schema was updated for the update at 17:17, and a copy was saved (this is just speculating, but it seems consistent with the facts that (1) an update was installed, and (2) there were lots of diffs from the previous backup). This still leaves the 07:22 file unaccounted for, but I think it's making some progress in explaining what's happening.

It's looking like 9.3 has implemented a mechanism to save copies of the config database whenever a change is made, which is a good thing. The only apparent bug is that rebooting the system floods the backup directory with a bunch of copies.

 

[cyberjock]

I don't think its odd at all that multiple backups exist simultaneously. I'm betting it's the result of my request to add database backups to the system dataset. I put the ticket in and it's closed (the ticket isn't viewable to the public).

If I had to guess I'd say it's doing backups at several "trigger" points such as database changes, bootup, shutdown, etc.

I doubt the bootup flooding with a bunch of copies is a bug. More than likely some trigger point is being triggered resulting in the copies. The reality of this is that 10MB of data is not going to significantly impact anyone. It's not going to create undue wear and tear on the pool nor is it going to consume lots of disk space.

If you are needing that 10MB of disk space... well.. you've got bigger problems when you can buy 4TB drives for cheap. ;)

 

[danb35]

No, it really isn't about disk space--as you observe, 10 MB is less than a drop in the bucket. The issue is one of the system behaving in a way that's unexpected, undocumented, and in at least one regard rather silly.

Backups of the config database are a good thing. Making them happen automatically on a schedule is a good thing. Making them happen automatically when there's a change to the configuration is an even better thing. Rotating them so that only a certain reasonable number are kept is better yet. The whole implementation is, IMO, a significant improvement on your HOWTO on scheduling backups of the config database, but as none of it is documented, it's therefore unexpected and leads to threads like this one, asking WTH is going on and trying to figure it out with blind guesses.

The part that's not so good is that it seems to make lots of identical copies when the system reboots, which kind of defeats the idea of keeping a certain number of backups--you could roll back the last 30 configuration changes you made, unless you've rebooted, in which case half of those (or perhaps more) are expired. In addition to being unexpected and undocumented, this behavior appears inconsistent with the rest of the backup behavior.

 

[cyberjock]

I can agree that there is a certain amount of defeated purpose. It could be that they haven't documented it because it's not officially working precisely how they want it. ;)

Still waiting for feedback on a dev on this.

 

[joeschmuck]

I too have the 30 files and three sets of them are in groups of 6, likely when I powered up the system (I went and blew some compressed air into the case and then relocated it back into the basement. I have a few other entries as well which I believe I can trace back to things I did.

Guess we will have to wait to see what Cyberjock finds out. Hopefully this will be documented as it could prove as a crucial item during a system recover. I'm glad the data is present.

 

[danb35]

After doing a little bit of digging in a mostly-unrelated thread, it seems this behavior was dropped with the 20150415 update.