Mac – Time Machine keeps asking to create new backup

backupnastime-machine

Every time a backup completes I get this message –

'Time Machine completed a verification of your backups. To improve reliability, Time Machine must create a new backup for you.'

I am backing up to Lacie Network Space 2 drive via wifi.

Does anybody know how to correct this?

Best Answer

This will not get fixed until Time Machine re-engineer its approach and move away from using a remote-mounted disk image over the network.

The problem lies due to network connections inherently being unreliable (more so wireless networks). However the file system (HFS+) was built for locally-attached disk and assumes that the connection is mostly reliable. Using Time Machine over the network is like writing to a hard drive in which you often unplug the cable mid-transfer. Eventually corruptions occur.

The only way to correct this is to file a bug report to increase the priority of fixing this within Apple's engineering group.

More information here.

Suitability of HFS Plus

Whilst Time Machine must use HFS Plus for most things, it's worth noting that the file system is not ideally suited for the task.

An example

Coincidence: a few hours after my first edition of this answer, my own Time Machine Backups volume (a sparse bundle disk image) suffered a file system failure. I'm certain that the underlying storage is OK – a ZFS pool scrubbed, without error, before and after the HFS Plus failure. For the record:

2013-06-07 18:02:54.332 com.apple.backupd[18433]    Starting automatic backup
2013-06-07 18:02:56.292 com.apple.backupd[18433]    Resizing backup disk image from 2.65 TB to 2.6 TB
2013-06-07 18:03:34.119 com.apple.backupd[18433]    Disk image /Volumes/tall/com.apple.backupd/GPES3E-gjp4-1.sparsebundle mounted at: /Volumes/Time Machine Backups
2013-06-07 18:03:35.244 com.apple.backupd[18433]    Backing up to: /Volumes/Time Machine Backups/Backups.backupdb
2013-06-07 18:03:44.013 com.apple.backupd[18433]    Inherited root volume OS, UUID: C5C41F95-133B-3EB0-9013-F94DAAA0D99B
2013-06-07 18:03:44.147 com.apple.backupd[18433]    Forcing deep traversal on source: "OS" (mount: '/' fsUUID: 03AF4C8A-66E8-3DE2-B30F-176C0C2337C3 eventDBUUID: BDCB9532-A4A8-4B94-A6C1-928FD741B07A)
2013-06-07 18:03:44.148 com.apple.backupd[18433]    Event store UUIDs don't match for volume: spare
2013-06-07 18:03:44.150 com.apple.backupd[18433]    Event store UUIDs don't match for volume: disk0s3
2013-06-07 18:03:47.612 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-103948 does not contain spare.  Skipping it.
2013-06-07 18:03:47.663 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-215311 does not contain spare.  Skipping it.
2013-06-07 18:03:47.714 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-075155 does not contain spare.  Skipping it.
2013-06-07 18:03:47.764 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-055748 does not contain spare.  Skipping it.
2013-06-07 18:03:47.827 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-220121 does not contain spare.  Skipping it.
2013-06-07 18:03:47.888 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-081211 does not contain spare.  Skipping it.
2013-06-07 18:03:47.966 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-215312 does not contain spare.  Skipping it.
2013-06-07 18:03:48.025 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-235752 does not contain spare.  Skipping it.
2013-06-07 18:03:48.087 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-140311 does not contain spare.  Skipping it.
2013-06-07 18:03:48.145 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-215718 does not contain spare.  Skipping it.
2013-06-07 18:03:48.202 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-005749 does not contain spare.  Skipping it.
2013-06-07 18:03:48.261 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-235753 does not contain spare.  Skipping it.
2013-06-07 18:03:48.321 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-160310 does not contain spare.  Skipping it.
2013-06-07 18:03:48.558 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-074020 does not contain spare.  Skipping it.
2013-06-07 18:03:48.619 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-025748 does not contain spare.  Skipping it.
2013-06-07 18:03:48.709 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-015751 does not contain spare.  Skipping it.
2013-06-07 18:03:48.904 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-025749 does not contain spare.  Skipping it.
2013-06-07 18:03:48.954 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-015752 does not contain spare.  Skipping it.
2013-06-07 18:03:49.004 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-130310 does not contain spare.  Skipping it.
2013-06-07 18:03:49.055 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-045748 does not contain spare.  Skipping it.
2013-06-07 18:03:49.162 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-215950 does not contain spare.  Skipping it.
2013-06-07 18:03:49.211 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-092036 does not contain spare.  Skipping it.
2013-06-07 18:03:49.273 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-035751 does not contain spare.  Skipping it.
2013-06-07 18:03:49.321 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-225752 does not contain spare.  Skipping it.
2013-06-07 18:03:49.371 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-065747 does not contain spare.  Skipping it.
2013-06-07 18:03:49.420 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-045749 does not contain spare.  Skipping it.
2013-06-07 18:03:49.470 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-213710 does not contain spare.  Skipping it.
2013-06-07 18:03:49.519 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-091305 does not contain spare.  Skipping it.
2013-06-07 18:03:49.589 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-150310 does not contain spare.  Skipping it.
2013-06-07 18:03:49.639 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-065748 does not contain spare.  Skipping it.
2013-06-07 18:03:49.688 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-074521 does not contain spare.  Skipping it.
2013-06-07 18:03:49.776 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-220105 does not contain spare.  Skipping it.
2013-06-07 18:03:49.838 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-225749 does not contain spare.  Skipping it.
2013-06-07 18:03:49.899 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-092118 does not contain spare.  Skipping it.
2013-06-07 18:03:50.119 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-120311 does not contain spare.  Skipping it.
2013-06-07 18:03:50.388 com.apple.backupd[18433]    Mobile backup /Volumes/MobileBackups/Backups.backupdb/GPES3E-gjp4-1/2013-06-07-035749 does not contain spare.  Skipping it.
2013-06-07 18:03:51.141 com.apple.backupd[18433]    Deep event scan at path:/ reason:must scan subdirs|require scan|
2013-06-07 18:03:51.141 com.apple.backupd[18433]    Finished scan
2013-06-07 18:16:29.077 com.apple.backupd[18433]    Deep event scan at path:/Volumes/spare reason:must scan subdirs|new event db|
2013-06-07 18:16:29.086 com.apple.backupd[18433]    Finished scan
2013-06-07 18:16:29.570 com.apple.backupd[18433]    Deep event scan at path:/Volumes/disk0s3 reason:must scan subdirs|new event db|
2013-06-07 18:16:29.786 com.apple.backupd[18433]    Finished scan
2013-06-07 18:16:30.310 com.apple.backupd[18433]    Found 1695685 files (84.93 GB) needing backup
2013-06-07 18:16:31.053 com.apple.backupd[18433]    109.44 GB required (including padding), 2 TB available
2013-06-07 18:54:10.918 com.apple.backupd[18433]    Unexpected result from MDBackupIndexFile (1) for: /Applications/Freenet/datastore/CHK-cache.hd, /Volumes/Time Machine Backups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-215332.inProgress/9086512E-E386-475E-AE99-34BAA1D2E485/OS/Applications/Freenet/datastore/CHK-cache.hd
2013-06-07 18:54:24.848 com.apple.backupd[18433]    Unexpected result from MDBackupIndexFile (1) for: /Applications/Freenet/datastore/CHK-store.hd, /Volumes/Time Machine Backups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-215332.inProgress/9086512E-E386-475E-AE99-34BAA1D2E485/OS/Applications/Freenet/datastore/CHK-store.hd
2013-06-07 19:03:44.609 com.apple.backupd[18433]    Copied 18.81 GB of 84.93 GB, 460244 of 1695685 items
2013-06-07 20:03:44.827 com.apple.backupd[18433]    Copied 34.12 GB of 84.93 GB, 815234 of 1695685 items
2013-06-07 21:03:54.004 com.apple.backupd[18433]    Copied 40.73 GB of 84.93 GB, 1013214 of 1695685 items
2013-06-07 22:03:54.678 com.apple.backupd[18433]    Copied 67.55 GB of 84.93 GB, 1508426 of 1695685 items
2013-06-07 22:28:43.226 com.apple.backupd[18433]    Copied 1786731 files (77.59 GB) from volume OS.
2013-06-07 22:28:49.157 com.apple.backupd[18433]    Unexpected result from MDBackupIndexFile (1) for: /Volumes/spare/Tocar y Luchar JAA.cdr, /Volumes/Time Machine Backups/Backups.backupdb/GPES3E-gjp4-1/2013-06-06-215332.inProgress/9086512E-E386-475E-AE99-34BAA1D2E485/spare/Tocar y Luchar JAA.cdr
2013-06-07 22:28:51.508 com.apple.backupd[18433]    Error: Flushing index to disk returned an error: 1
2013-06-07 22:28:51.508 com.apple.backupd[18433]    Copied 1786746 files (77.59 GB) from volume spare.
2013-06-07 22:29:11.108 com.apple.backupd[18433]    Backup canceled.
2013-06-07 22:29:23.227 com.apple.backupd[18433]    Ejected Time Machine disk image: /Volumes/tall/com.apple.backupd/GPES3E-gjp4-1.sparsebundle
2013-06-07 23:10:44.791 com.apple.backupd[28884]    Starting automatic backup
2013-06-07 23:10:45.269 com.apple.backupd[28884]    Backup failed with error: 1002
2013-06-07 23:10:45.382 com.apple.backupd[28884]    Starting automatic backup
2013-06-07 23:10:46.446 com.apple.backupd[28884]    Resizing backup disk image from 2.6 TB to 2.6 TB
2013-06-07 23:10:50.162 com.apple.backupd[28884]    Runtime corruption detected on /Volumes/tall/com.apple.backupd/GPES3E-gjp4-1.sparsebundle (fsck_hfs -q termination status: 3)

the message at 2013-06-07 22:28:49 is eye-catching, but expected in my case (symptom of a bug involving HFS Plus; a corruption that involves AppleFSCompression) – probably negligible in the context of this answer
the message at 2013-06-07 22:28:51 may be more relevant to the file system failure.

/private/var/log/fsck_hfs.log then showed:

/dev/rdisk7s2: fsck_hfs run at Fri Jun  7 23:10:48 2013
/dev/rdisk7s2: ** /dev/rdisk7s2 (NO WRITE)
/dev/rdisk7s2:    Executing fsck_hfs (version diskdev_cmds-557.3.1~5).
QUICKCHECK ONLY; FILESYSTEM DIRTY

/dev/rdisk7s2: fsck_hfs run at Fri Jun  7 23:10:49 2013
/dev/rdisk7s2: ** /dev/rdisk7s2 (NO WRITE)
/dev/rdisk7s2:    Executing fsck_hfs (version diskdev_cmds-557.3.1~5).
QUICKCHECK ONLY; FILESYSTEM DIRTY

Confirming that no error affected the underlying storage at the time:

GPES3E-gjp4-1:~ gjp22$ date
Sat  8 Jun 2013 06:57:46 BST
GPES3E-gjp4-1:~ gjp22$ uptime
 6:57  up 21:51, 5 users, load averages: 0.92 1.27 1.37
GPES3E-gjp4-1:~ gjp22$ zpool status
  pool: gjp22
 state: ONLINE
 scan: scrub repaired 0 in 24h8m with 0 errors on Sat May 25 23:25:38 2013
config:

    NAME                                         STATE     READ WRITE CKSUM
    gjp22                                        ONLINE       0     0     0
      GPTE_71B8BDA2-3EBA-4B91-9E1C-2AE2B1DAAD06  ONLINE       0     0     0  at disk3s2
    cache
      GPTE_2605CCB0-67B7-4C93-A4B1-83EF764CE617  OFFLINE        1.48Ki     0

errors: No known data errors

  pool: tall
 state: ONLINE
 scan: scrub repaired 0 in 28h10m with 0 errors on Sun May 26 18:47:22 2013
config:

    NAME                                         STATE     READ WRITE CKSUM
    tall                                         ONLINE       0     0     0
      GPTE_78301A52-4AFF-4D96-8DE9-E76ABC14909C  ONLINE       0     0     0  at disk2s2
      GPTE_99056308-F5E2-4314-852C-4DA04732A2D0  ONLINE       0     0     0  at disk6s2

errors: No known data errors
GPES3E-gjp4-1:~ gjp22$

In simple terms

Whilst we'd like a solution, file system failures such as this seem to be:

unpredictable
unavoidable
sometimes irreparable.

In the absence of a good solution, my best advice is to not rely on a single Time Machine backup. The risk of eventual failure and inability to repair is simply too high.

Degrees of failure

In the past I sometimes forced fsck_hfs(8) to rebuild b-tree files … with limited success but not certainty. Whilst a file system may appear to be OK (in Disk Utility and the like) I would not no longer trust it for Time Machine backup or restoration purposes.

In the most recent case (above) multiple applications of force (multiple rebuilds of the catalog b-tree, a rebuild of the extended attributes b-tree and a rebuild of the extents b-tree) have not led to a verifiable file system. I have debug logs from these attempts, which I'll not begin to summarise here; they're massive.

With locally attached disks (USB 2.0), attempts to repair Time Machine backup volumes can be extraordinarily time consuming. Wireless – over AFP – you may find the time required intolerable.

Time Machine - Troubleshooting – C13. "…Time Machine must create a new backup for you." (James Pond) includes much useful information. Essentially:

… backups are corrupted beyond Disk Utility's ability to fix …

When OS X reports that an HFS Plus file system appears to be OK, there may be significant issues with the disk – issues that OS X simply can not detect.

As corruption has occurred more than once, there may be a problem with:

hardware, firmware and/or software of the NAS.

What make and model is the NAS?

Hard disks of the NAS

If the OS of the NAS allows you to verify integrity of blocks on its disks: please do so.

If the OS of the NAS lacks that capability, then aim to boot the hardware with a different OS that's more suitable for testing. Options might include Ubuntu and a run of badblocks.

Checks of this type:

will be time consuming; but
should help you to determine whether the state of the disk(s) is contributory to the multiple failures.

Mac – Automatically shrink existing Time Machine Backup to a fixed size

Time Machine will respect a size determination - but only when you make the container. This functionality is all that Apple provides for native backup so you'd need a custom setup to do what you ask, and you can't limit things once you've started backing up to a container.

Going forward if you want to make a new restricted container, the concept isn't hard to map out though.

make a new container on the synology and be sure to enforce the size constraints when you start the process.

Server.app does that easily - I'm not aware of synology code that reverse engineered that feature, but would be surprised if it's not on GitHub or published somewhere public.

At that point, you could delete all backups of user folders that are large and then block by block copy the old backup data to the new destination and then inherit the backup.

You can also thin backup intervals from the command line or script this automation as well.

Lots and lots of work, but it might be worth it as a project if someone is inclined.

When I'm in your shoes, I just copy off the old "too large" backup to an offline hard drive and put it on a shelf and start over with new backups of the size you like. In 6 months or a year - wipe that old drive unless you really feel you need that older history.