"Time Machine completed a verification of your backups."

Hi, just to clear out your questions:

• the connection to the NAS is ethernet-based, not WiFi
• when I talk of individual sparse elements, I'm talking about the 8Mb small files that a sparse bundle is made of. As my backup is currently being rebuild I'd say I had a volume of 500-600 Gb, that's more than 75000 such parts chained together. This adds to the complexity, as you also have the linking of hese to add to the equation.
• As I say, I had similar issues with the TimeCapsule. I switched everything to the NAS when I had to replace my iMac HD when it was broken. Restoring the backup from the (1TB) time machine and then re-initiating a full backup didn't work without first resetting the disk on the TimeCapsule (as both backup couldn't coexist at the same time due to space problems).

Kind regards,

Raf

Raf wrote:

. . .

when I talk of individual sparse elements, I'm talking about the 8Mb small files that a sparse bundle is made of. As my backup is currently being rebuild I'd say I had a volume of 500-600 Gb, that's more than 75000 such parts chained together. This adds to the complexity, as you also have the linking of hese to add to the equation.

That doesn't make it any more complex . . . just larger. You might as well say, the more files you have on your system, the more complex it is.

As I say, I had similar issues with the TimeCapsule. I switched everything to the NAS when I had to replace my iMac HD when it was broken. Restoring the backup from the (1TB) time machine and then re-initiating a full backup didn't work without first resetting the disk on the TimeCapsule (as both backup couldn't coexist at the same time due to space problems).

That's a different problem. The full system restore (assuming that's what you mean) was changed in Snow Leopard to leave a "trail" in the SystemMigration.log, so Time Machine's next backup could figure out what happened and "associate" the new drive with the old backups, and only do an incremental backup.

Unfortunately, that didn't work a lot of the time, but seems to have no connection to the size of the backups, but something going wrong in that log.

It did it again, this time with no alert on the previous backup:

2/12/12 11:42:55.672 AM com.apple.backupd: Starting standard backup

2/12/12 11:42:56.638 AM com.apple.backupd: Attempting to mount network destination URL: afp://TimeMachine@Qnap-TS410.local/TMBackup

2/12/12 11:43:00.193 AM com.apple.backupd: Mounted network destination at mountpoint: /Volumes/TMBackup using URL: afp://TimeMachine@Qnap-TS410.local/TMBackup

2/12/12 11:43:20.144 AM com.apple.backupd: QUICKCHECK ONLY; FILESYSTEM CLEAN

2/12/12 11:43:22.626 AM com.apple.backupd: Disk image /Volumes/TMBackup/rjosse-iMac-i7.sparsebundle mounted at: /Volumes/Time Machine Backups

2/12/12 11:43:22.852 AM com.apple.backupd: Backing up to: /Volumes/Time Machine Backups/Backups.backupdb

2/12/12 11:48:50.846 AM com.apple.backupd: 8.23 GB required (including padding), 2.18 TB available

2/12/12 12:22:41.938 PM com.apple.backupd: Copied 216959 files (2.0 GB) from volume Machiavel.

2/12/12 12:23:08.674 PM com.apple.backupd: 3.80 GB required (including padding), 2.18 TB available

2/12/12 12:24:26.948 PM com.apple.backupd: Copied 17379 files (12.3 MB) from volume Machiavel.

2/12/12 12:25:50.412 PM com.apple.backupd: Starting post-backup thinning

2/12/12 12:25:50.412 PM com.apple.backupd: No post-back up thinning needed: no expired backups exist

2/12/12 12:25:50.561 PM com.apple.backupd: Backup completed successfully.

2/12/12 12:26:04.375 PM com.apple.backupd: Ejected Time Machine disk image.

2/12/12 12:26:04.992 PM com.apple.backupd: Ejected Time Machine network volume.

2/12/12 12:42:57.008 PM com.apple.backupd: Starting standard backup

2/12/12 12:42:57.740 PM com.apple.backupd: Attempting to mount network destination URL: afp://TimeMachine@Qnap-TS410.local/TMBackup

2/12/12 12:42:59.364 PM com.apple.backupd: Mounted network destination at mountpoint: /Volumes/TMBackup using URL: afp://TimeMachine@Qnap-TS410.local/TMBackup

2/12/12 12:43:19.069 PM com.apple.backupd: QUICKCHECK ONLY; FILESYSTEM DIRTY

2/12/12 12:43:19.560 PM com.apple.backupd: Runtime corruption detected on /Volumes/TMBackup/rjosse-iMac-i7.sparsebundle (fsck_hfs -q termination status: 3)

2/12/12 12:43:19.799 PM com.apple.backupd: Network destination already mounted at: /Volumes/TMBackup

2/12/12 12:46:52.943 PM com.apple.backupd: Recovery backup declined by user.

2/12/12 12:46:53.379 PM com.apple.backupd: Backup canceled.

Checked on the kernel entries and indeed had issues with the virtual volume yesterday and today:

2/11/12 9:18:44.000 AM kernel: hfs_swap_BTNode: record #-1 invalid offset (0x0000)

2/11/12 9:18:44.000 AM kernel: hfs: node=105624 fileID=4 volume=Time Machine Backups device=/dev/disk3s2

2/11/12 9:18:44.000 AM kernel:

2/11/12 9:18:44.000 AM kernel: hfs: Runtime corruption detected on Time Machine Backups, fsck will be forced on next mount.

2/12/12 11:43:00.000 AM kernel: AFP_VFS afpfs_mount: /Volumes/TMBackup, pid 670

2/12/12 11:43:23.000 AM kernel: hfs: BlockMarkFreeInternal() trying to free unallocated blocks (72968970,1) on volume Time Machine Backups

2/12/12 11:43:23.000 AM kernel:

2/12/12 11:43:23.000 AM kernel: hfs: Runtime corruption detected on Time Machine Backups, fsck will be forced on next mount.

2/12/12 11:43:27.000 AM kernel: AppleBCM5701Ethernet: 0 1 BCM5701Enet::replaceOrCopyPacket worked after N tries

2/12/12 11:55:57.000 AM kernel: (default pager): [KERNEL]: ps_allocate_cluster - send HI_WAT_ALERT

2/12/12 11:55:57.000 AM kernel: macx_swapon SUCCESS

2/12/12 12:00:16.000 PM kernel: (default pager): [KERNEL]: ps_select_segment - send HI_WAT_ALERT

2/12/12 12:00:16.000 PM kernel: macx_swapon SUCCESS

2/12/12 12:26:05.000 PM kernel: AFP_VFS afpfs_unmount: /Volumes/TMBackup, flags 0, pid 962

I'm switching back to the TimeCapsul, will switch back to the Qnap next week, 16 hours to create a new backup is far too much for my patience this week-end.

Kind regards,

Raf

RAF,

rookie question, but where are you getting that log file?

I'm using the Console application (it is located in the Utilities folder in the Applications folder), and I created views on the log file that would only list events related to Backup in one view and Kernel in a second. Looking at the log file without this may be difficults as many applications add lines to the file.

I'm currently at work, but if you need some help to create the views, I'd be glad to help.

Kind regards.

ok, i fiddled with it. you just pick "new system log query" and search for what items? backup daemon and any mention of time machine?

Select your system.log in the sidebar and filter for Backupd.

To look back further, in the archived older logs, open the /var/log folder in the sidebar and select the system.log.0.bz2 etc. files.

perfect. thx.

Dear lost in Austin, to make it permanent, in new system log query, select Sender contains Backupd (as mentioned by Pondini), for kernel events, Sender is equal to kernel.

Kind regards,

Raf

hoppah wrote:

. . .

2/13/12 8:13:53.812 AM com.apple.backupd Failed to create backup of Time Machine Information file /Volumes/ReadyNAS/Owner’s Mac Pro.sparsebundle/com.apple.TimeMachine.MachineID.bckup, error: (null)

That's interesting. TM couldn't copy one of the control files in the sparse bundle (right-click the sparse bundle in the Finder and select See Package Contents).

I presume you've edited the name of your Mac in these logs ("Owner's Mac Pro"). Oddly enough, the names of your Computer or network can cause problems, sometimes intermittently; a couple of other messages look like there may be some special characters in yours. The message is different, but check them per #C9 in Time Machine - Troubleshooting.

I'd like to extend the log horizon. Are the logs archived and deleted via cron?

No, by the newsyslog process. See the blue box in OSX Maintenance Scripts for details and where to find instructions for altering the defaults.

hoppah wrote:

Indeed, names have been changed to protect the guilty. The NAS' name is a nice, POSIX-compliant set of six alphanumeric characters separated into two groups of three by a "-". The computer name is my full name, which the OS generated from, of course, my full name when I first set up my admin account. This name is in the format:

First M. Last

with spaces and a period after the M.I., of course.

Just be sure it's no more than 25 characters long, total.

It occurred to me that a character problem may be the cause, way back when this started, as I've seen many such things in the past, however, this would not explain why it works just fine for a full week before blowing up every Monday morning.

It can be intermittent, for some reason. I've never noticed it being that regular, but since we don't know why it fails when it does . . .

hoppah,

any updates for us?

yesterday i had same thing happen to my (3rd) first gen Time Machine (yes, 1st two died due to thermal problems and were replaced by Apple. just got this one last month). coincidentally, i am also having trouble with Chronosync backups to my NAS (Synology DS210+). just sent them a note and have no idea if these are related, but 2 problems associated with backups in 1 day was at least worth noting.

i happened to be on wifi when the TM error showed up. i guess i'll start a wired backup today. 3 TM's and now this... maybe time to consider a change to the backup strategy!