NETGEAR is aware of a growing number of phone and online scams. To learn how to stay safe click here.
Forum Discussion
Integrity of Time Machine backups over time?
Hi, I wonder how frequent one should accept to redo a Time Machine backup (of say 100-200 GB) on a ReadyNAS 314? I have had ReadyNAS 314 now for soon 3 months using firmware 6.2.4 and needed to r...
Hello again,
today timemachine reported again that my backups are not reliable anymore and the backup must be started from scratch.
I did do nothing, no ReadyNAS OS update so far. Still running ReadyOS 6.4.2 and my timemachine backup history started 20th December 2015.
I noticed that the last successful timemachine backup run this morning at 10:29am (don't know if it started or completed at this time; the information is from timemachine system settings window). Surprisingly the ReadyNAS sent me an eMail today at 10:30am reporting the "Scrub started for volume data.".
I only have a single volume configured on my ReadyNAS, so I'm wondering if maybe the ReadyNAS / ReadyOS Scrub Data process invalidated my timemachine backup.
Does anyone see a chance to see from the ReadyNAS / ReadyOS log files if the scrub data process relocated data in the background while timemachine backup was still running?
Many thanks and regards,
Holger
I reviewed the OSX console and it looks like the timemachine backup was still running when data scrubbing started:
Excerpt console log:
01.06.16 10:08:03,269 com.apple.backupd[14121]: Found 115929 files (7.33 GB) needing backup
01.06.16 10:08:04,609 com.apple.backupd[14121]: 10.92 GB required (including padding), 501.97 GB available
...
01.06.16 10:27:36,408 com.apple.backupd[14121]: Copied 116307 items (7.33 GB) from volume Macintosh HD. Linked 13110.
01.06.16 10:29:41,270 com.apple.backupd[14121]: Created new backup: 2016-06-01-102939
01.06.16 10:29:43,233 com.apple.backupd[14121]: Starting post-backup thinning
...
01.06.16 10:33:42,893 com.apple.backupd[14121]: Deleted /Volumes/Time Machine-Backups/Backups.backupdb/Mac-Mini/2016-05-02-100835 (36.1 MB)
01.06.16 10:33:42,894 com.apple.backupd[14121]: Post-backup thinning complete: 1 expired backups removed
01.06.16 10:33:44,522 com.apple.backupd[14121]: Backup completed successfully.
...
01.06.16 12:34:13,000 kernel[0]: hfs: node=52917 fileID=4 volume=Time Machine-Backups device=/dev/disk2s2
01.06.16 12:34:13,000 kernel[0]: hfs_mark_inconsistent: Runtime corruption detected on Time Machine-Backups, fsck will be forced on next mount.
01.06.16 12:34:25,000 kernel[0]: hfs: unmount initiated on Time Machine-Backups on device disk2s2
01.06.16 12:34:46,958 com.apple.backupd[14121]: Ejected Time Machine disk image: /Volumes/holger's timemachine/Mac-Mini.sparsebundle
01.06.16 12:34:48,345 com.apple.backupd[14121]: Ejected Time Machine network volume.
And here the excerpt from the readynasd.log:
Jun 01 10:01:59 PrivateNAS readynasd[2917]: ReadyNASOS background service started.
Jun 01 10:18:34 PrivateNAS readynasd[2917]: Antivirus scanner definition file was updated to 201606010628.
Jun 01 10:30:05 PrivateNAS readynasd[2917]: Scrub started for volume data.
Any idea where to find more information in the ReadyNAS logs (files from download logs) what data scrubbing did in the background?
Thanks,
Holger
I reviewed all the other ReadyNAS log files downloaded. Here are some message from time of last successful backup / data scrubbing:
dmesg.log:
[Wed Jun 1 10:30:04 2016] md: requested-resync of RAID array md127
[Wed Jun 1 10:30:04 2016] md: minimum _guaranteed_ speed: 30000 KB/sec/disk.
[Wed Jun 1 10:30:04 2016] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for requested-resync.
[Wed Jun 1 10:30:04 2016] md: using 128k window, over a total of 971910784k.system.log:
Jun 01 10:30:44 PrivateNAS mdadm[2738]: RebuildStarted event detected on md device /dev/md127, component device resync
volume.log (only for the disks showing relocation error):
==============================================
Disks
==============================================
Disk sdd:
HostID: 2fe4c7fe
Flags: 0x0
Size: 1953525168 (931 GB)
Free: 4054
Controller 0
Channel: 0
Model: Hitachi HUA721010KLA330
Serial: GTE002PAJ6XALE
Firmware: GKAOAB0A
SMART data
Reallocated Sectors: 2
Reallocation Events: 2
Spin Retry Count: 0
Current Pending Sector Count: 0
Uncorrectable Sector Count: 0
Temperature: 45
Start/Stop Count: 4670
Power-On Hours: 27424
Power Cycle Count: 698
Load Cycle Count: 4726
Latest Self Test: Passed...
RAID data-0:
Device: md127
HostID: 2fe4c7fe
UUID: e26e67dc-7a04-fafe-4aaa-75eda72ab11e
Size: 5831464704
Component size: 1944083825
Level: 5
State: redundant
Action: scrubbing for errors (auto-repair)
Sync progress: 277079056/5831464704
Sync speed: 728 KB/sec
Flags 0x408
Members: 4
Pool: data
Disks:
sdd:
HostID: 2fe4c7fe
Flags: 0x0
Size: 1953525168 (931 GB)
Free: 4054
Controller 0
Channel: 0
Model: Hitachi HUA721010KLA330
Serial: GTE002PAJ6XALE
Firmware: GKAOAB0A
SMART data
Reallocated Sectors: 2
Reallocation Events: 2...
smart_history.log:
model serial realloc_sect realloc_evnt spin_retry_cnt ioedc cmd_timeouts pending_sect uncorrectable_err ata_errors timestamp time
-------------------- -------------------- ------------ ------------ -------------- ---------- ------------ ------------ ----------------- ---------- ---------- -------------------
Hitachi HUA721010KLA GTE002PAJ6XALE 2 2 0 -1 -1 0 0 0 1416781844 2014-11-23 22:30:44
Hitachi HUA721010KLA GTF002PAJ0V2TF 0 0 0 -1 -1 0 0 0 1416781844 2014-11-23 22:30:44
Hitachi HUA721010KLA GTF002PAHZVHJF 0 0 0 -1 -1 0 0 0 1416781844 2014-11-23 22:30:44
Hitachi HUA721010KLA GTE002PAJ6YKTE 0 0 0 -1 -1 0 0 0 1416781844 2014-11-23 22:30:44... and finally my update history to confirm I did not do a ReadyOS update which resulted into invalidating timemachine:
[2014/11/23 15:28:09] Factory default initiated by Frontview!
[2014/11/23 15:28:36] Defaulting to X-RAID2 mode, RAID level 5
[2014/11/23 15:29:04] Factory default initiated on ReadyNASOS 6.1.9 (1409791183).
[2014/11/24 10:44:06] Updated from ReadyNASOS 6.1.9 () to 6.2.0 (ReadyNASOS).
[2014/12/23 06:46:22] Updated from ReadyNASOS 6.2.0 (ReadyNASOS) to 6.2.1 (ReadyNASOS).
[2014/12/29 02:17:03] Updated from ReadyNASOS 6.2.1 (ReadyNASOS) to 6.2.2 (ReadyNASOS).
[2015/05/06 23:50:18] Updated from ReadyNASOS 6.2.2 (ReadyNASOS) to 6.2.4 (ReadyNASOS).
[1969/12/31 17:00:58] Updated from ReadyNASOS 6.2.4 (ReadyNASOS) to 6.4.0 (ReadyNASOS).
[2015/11/22 12:49:43] Updated from ReadyNASOS 6.4.0 (ReadyNASOS) to 6.4.1 (RC1).
[2015/12/02 23:41:22] Updated from ReadyNASOS 6.4.1 (RC1) to 6.4.1 (ReadyNASOS).
[2016/03/21 12:38:26] Updated from ReadyNASOS 6.4.1 (ReadyNASOS) to 6.4.2 (ReadyNASOS).If there's another log file to review, please let me know.
Regards,
Holger
NETGEAR Academy
Boost your skills with the Netgear Academy - Get trained, certified and stay ahead with the latest Netgear technology!
Join Us!
