So I have a 500GB Time Capsule stuck somewhere in the house, to which all the Macs are backed up by Time Machine. Well, actually, my work MacBook Pro gets backed up on the TC’s internal hard drive, while all the other Macs (that’s one G5 iMac, a G4 iBook and a core2duo MacBook) are backed-up to a 500GB USB HD that’s hooked-up to the TC.
The great thing with TC/TM is that, since a couple versions of Leopard, the backups can be done over the LAN via Ethernet OR Airport. While TM does backups to external HD as simple subfolders, when you backup to a network drive, TM creates a sparsebundle disk image using your computer’s name and mac address (well, the MAC address of the network interface you used when doing the first ever TM backup of said machine).

On Monday, while TM was doing it’s hourly thing, there was a power outage in the house. When it went back live, I found out TM couldn’t backup my MacBook Pro anymore, it threw an error saying that it could not find the backup disk. I checked and could see the TC alright on the LAN, and the sparsebundle for my laptop was clearly there… So I rebooted the TC, but to no result. Them I tried to mount manually the sparsebundle: the Finder grinded away for a loooong while before giving up and throwing an error stating that the image had “no filesystem”. Yikes!

I went and had a look in my system logs and here is what I found:

May 28 08:29:14 rangiroa /System/Library/CoreServices/backupd[1607]: Backing up to: /Volumes/Backup of rangiroa/Backups.backupdb
May 28 08:31:17 rangiroa /System/Library/CoreServices/backupd[1607]: Stopping backupd to allow ejection of backup destination disk!
May 28 08:31:17 rangiroa /System/Library/CoreServices/backupd[1607]: Error: (6) getxattr for key:com.apple.backupd.SnapshotState path:/Volumes/Backup of rangiroa/Backups.backupdb/rangiroa/2008-04-29-102105
May 28 08:31:17 rangiroa /System/Library/CoreServices/backupd[1607]: Error: (6) getxattr for key:com.apple.backupd.SnapshotContainer path:/Volumes/Backup of rangiroa/Backups.backupdb/rangiroa/2008-04-29-102105
May 28 08:31:17 rangiroa /System/Library/CoreServices/backupd[1607]: Error: (-36) Creating directory 2008-05-28-083117.inProgress
May 28 08:31:17 rangiroa /System/Library/CoreServices/backupd[1607]: Failed to make snapshot container.
May 28 08:31:17 rangiroa /System/Library/CoreServices/backupd[1607]: Error: (-36) Creating directory rangiroa 2

[...] 998 of them [...]

May 28 08:31:18 rangiroa /System/Library/CoreServices/backupd[1607]: Backup failed with error: 2
May 28 08:31:30 rangiroa /System/Library/CoreServices/backupd[1635]: Mounting disk image /Volumes/Time Capsule/rangiroa_0017f2cb63cb.sparsebundle
May 28 08:31:30 rangiroa /System/Library/CoreServices/backupd[1635]: Failed to attach to disk image, returned: 35
May 28 08:31:30 rangiroa /System/Library/CoreServices/backupd[1635]: Failed to mount disk image /Volumes/Time Capsule/rangiroa_0017f2cb63cb.sparsebundle
May 28 08:31:30 rangiroa /System/Library/CoreServices/backupd[1635]: Ejected Time Machine network volume.

So the Finder could not attach the disk image, nor mount it…

And you know, there is no way to directly access the HD in the Time Capsule, meaning you can’t simply do a disk utility check on it. Wai you’ll say, you can use Disk Utility to check and repair a disk image, but to do that, said Disk utility first tries to mount the image, which, of course, failed in my case… So no luck with Disk Utility.

So I copied the 160GB sparsebundle to a USB HD, and went on trying to fix it… I did a lot of googling for the problem, but all I found was loads of complaints, but no solutions, until I stumbled on this post over at macosxhints.com. It says the guy managed to repair his sparsebundle using some terminal wizardry involving the use of the hdiutl command:

sudo hdiutil mount -nomount -readwrite /path/to/sparseimage

So I tried it: I launched Terminal, typed the correct command and path to the image, at which point I got a huge CPU spike while nothing happended in the Terminal, indicating that some process was running but giving no feedback. Looking at the Activity Monitor showed a process called fsck_hfs using about 60% of one CPU. fsck_hfs does, according to OSX’s man page (”man fsck_hfs”) , an HFS file system consistency check.
Funny thing is that I left it running for quite a while (we are dealing with a 160GB image, with hundreds of thousands of files), and after a couple hours, it failed! Argh!

But then, out of pure luck, I checked Disk Utility, and there in the sidebar was my sparsebundle showing that it contained an unmounted disk image called “backup of rangiroa”… I then decided to launch a repair on it, which started and after about 30 minutes started founding a whole bunch of errors, and fixing them:

/dev/rdisk2s2: fsck_hfs run at Tue May 27 15:47:11 2008
/dev/rdisk2s2: ** /dev/rdisk2s2 (NO WRITE)
/dev/rdisk2s2: QUICKCHECK ONLY; FILESYSTEM DIRTY
[...]
/dev/rdisk2s2: fsck_hfs run at Tue May 27 15:47:11 2008
/dev/rdisk2s2: ** /dev/rdisk2s2
/dev/rdisk2s2: ** Checking Journaled HFS Plus volume.
/dev/rdisk2s2: ** Detected a case-sensitive catalog.
/dev/rdisk2s2: ** Checking Extents Overflow file.
/dev/rdisk2s2: ** Checking Catalog file.
/dev/rdisk2s2: Keys out of order
/dev/rdisk2s2: (4, 89246)
/dev/rdisk2s2: ** Rebuilding Catalog B-tree.
/dev/rdisk2s2: Invalid record count
/dev/rdisk2s2: (4, 785)
/dev/rdisk2s2: Invalid node structure
[... thousands of them]
/dev/rdisk2s2: ** Rechecking volume.
/dev/rdisk2s2: ** Checking Journaled HFS Plus volume.
/dev/rdisk2s2: ** Detected a case-sensitive catalog.
/dev/rdisk2s2: Invalid B-tree node size
/dev/rdisk2s2: (8, 0)
/dev/rdisk2s2: ** Volume check failed.

ARGH!
but then it went on:

/dev/rdisk2s2: fsck_hfs run at Tue May 27 16:19:39 2008
/dev/rdisk2s2: ** /dev/rdisk2s2
/dev/rdisk2s2: ** Checking Journaled HFS Plus volume.
/dev/rdisk2s2: ** Detected a case-sensitive catalog.
/dev/rdisk2s2: ** Checking Extents Overflow file.
/dev/rdisk2s2: ** Checking Catalog file.
/dev/rdisk2s2: Keys out of order
/dev/rdisk2s2: (4, 89246)
/dev/rdisk2s2: ** Rebuilding Catalog B-tree.

/dev/rdisk2s2: fsck_hfs run at Tue May 27 17:32:47 2008
/dev/rdisk2s2: (S,”Checking Journaled HFS Plus volume.”,0)
/dev/rdisk2s2: (S,”Detected a case-sensitive catalog.”,0)
/dev/rdisk2s2: (S,”Checking Extents Overflow file.”,0)
/dev/rdisk2s2: (1 %)
[...]
/dev/rdisk2s2: (S,”Checking Catalog file.”,0)
[...]
/dev/rdisk2s2: (40 %)
/dev/rdisk2s2: (E,”Keys out of order”,0)
/dev/rdisk2s2: (S,”Rebuilding Catalog B-tree.”,0)
/dev/rdisk2s2: (S,”Rechecking volume.”,0)
/dev/rdisk2s2: (S,”Checking Journaled HFS Plus volume.”,0)
/dev/rdisk2s2: (S,”Detected a case-sensitive catalog.”,0)
/dev/rdisk2s2: (S,”Checking Extents Overflow file.”,0)
/dev/rdisk2s2: (1 %)
/dev/rdisk2s2: (2 %)
/dev/rdisk2s2: (S,”Checking Catalog file.”,0)
[...]
/dev/rdisk2s2: (45 %)
/dev/rdisk2s2: (E,”Incorrect number of thread records”,0)
/dev/rdisk2s2: (S,”Checking multi-linked files.”,0)
/dev/rdisk2s2: (E,”Incorrect number of file hard links”,0)
/dev/rdisk2s2: (S,”Checking Catalog hierarchy.”,0)
[...]
/dev/rdisk2s2: (E,”Invalid directory item count”,0)
/dev/rdisk2s2: (E,”(It should be %@ instead of %@)”,2)
/dev/rdisk2s2: 11692
/dev/rdisk2s2: 11690
/dev/rdisk2s2: (85 %)

/dev/rdisk2s2: fsck_hfs run at Tue May 27 18:27:13 2008
/dev/rdisk2s2: ** /dev/rdisk2s2 (NO WRITE)
/dev/rdisk2s2: QUICKCHECK ONLY; FILESYSTEM DIRTY
/dev/rdisk2s2: (E,”Incorrect folder count in a directory (id = %@)”,1)
/dev/rdisk2s2: 19
/dev/rdisk2s2: (E,”(It should be %@ instead of %@)”,2)
/dev/rdisk2s2: 11692
/dev/rdisk2s2: 11690
/dev/rdisk2s2: (S,”Checking Extended Attributes file.”,0)
/dev/rdisk2s2: (E,”Overlapped extent allocation (file %@)”,1)
/dev/rdisk2s2: 9899556 /.HFS+ Private Directory Data
[...]
/dev/rdisk2s2: (S,”Checking multi-linked directories.”,0)
/dev/rdisk2s2: (E,”Incorrect number of directory hard links”,0)
/dev/rdisk2s2: (S,”Checking volume bitmap.”,0)
/dev/rdisk2s2: (E,”Volume Bit Map needs minor repair”,0)
/dev/rdisk2s2: (S,”Checking volume information.”,0)
/dev/rdisk2s2: (E,”Invalid volume free block count”,0)
/dev/rdisk2s2: (E,”(It should be %@ instead of %@)”,2)
/dev/rdisk2s2: 84245711
/dev/rdisk2s2: 80893131
/dev/rdisk2s2: (E,”Volume Header needs minor repair”,0)
/dev/rdisk2s2: (100 %)
/dev/rdisk2s2: (S,”Repairing volume.”,0)
/dev/rdisk2s2: (E,”Previous ID in a hard link chain is incorrect (id = %@)”,1)
[...]
/dev/rdisk2s2: 1
/dev/rdisk2s2: 2
/dev/rdisk2s2: (E,”Orphaned directory hard link (id = %@)”,1)
/dev/rdisk2s2: 9787044
/dev/rdisk2s2: (S,”Look for links to corrupt files in DamagedFiles directory.”,0)
/dev/rdisk2s2: (S,”Rechecking volume.”,0)
/dev/rdisk2s2: (S,”Checking Journaled HFS Plus volume.”,0)
/dev/rdisk2s2: (S,”Detected a case-sensitive catalog.”,0)
/dev/rdisk2s2: (S,”Checking Extents Overflow file.”,0)
[...]
/dev/rdisk2s2: (85 %)
/dev/rdisk2s2: (E,”HasFolderCount flag needs to be set (id = %@)”,1)
[...]
/dev/rdisk2s2: 25
/dev/rdisk2s2: (S,”Checking Extended Attributes file.”,0)
/dev/rdisk2s2: (S,”Checking multi-linked directories.”,0)
/dev/rdisk2s2: (S,”Checking volume bitmap.”,0)
/dev/rdisk2s2: (S,”Checking volume information.”,0)
/dev/rdisk2s2: (100 %)
/dev/rdisk2s2: (S,”Repairing volume.”,0)
/dev/rdisk2s2: (S,”Rechecking volume.”,0)
/dev/rdisk2s2: (S,”Checking Journaled HFS Plus volume.”,0)
/dev/rdisk2s2: (S,”Detected a case-sensitive catalog.”,0)
/dev/rdisk2s2: (S,”Checking Extents Overflow file.”,0)
[...]
/dev/rdisk2s2: (85 %)
/dev/rdisk2s2: (S,”Checking Extended Attributes file.”,0)
/dev/rdisk2s2: (S,”Checking multi-linked directories.”,0)
/dev/rdisk2s2: (S,”Checking volume bitmap.”,0)
/dev/rdisk2s2: (S,”Checking volume information.”,0)
/dev/rdisk2s2: (100 %)
/dev/rdisk2s2: (S,”The volume %@ was repaired successfully.”,1)
/dev/rdisk2s2: Backup of rangiroa

Yes, “The volume %@ was repaired successfully.” That took about 4hrs…

I then double-clicked on the sparsebundle in the Finder and, ta-da, IT MOUNTED!

I then right-clicked on the Time Machine icon in the Dock, chose “Browse another Time Machine backup…”, pointed it to my repaired image, and the TM browser launched successfully!

I then copied back the repaired sparsebundle on the Time Capsule HD over the LAN, and launched a Time Machine backup… which did find the backup disk and hang there display a “Preparing backup” status for a long time. A bit scared I went and looked in the backupd log to find this message:

May 28 22:40:35 rangiroa /System/Library/CoreServices/backupd[411]: Node requires deep traversal:/ reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|

So all it was doing was actually rechecking for file changes because it found out that the databse that stores all the file changes notified by Spotlight was “untrustable”, probably because the repair had found a number of orphaned hardlinks and such…

So I decided to let it go and, after about 45 minutes, it started doing the actual backup.

So, now all is back on tracks and working fine.

My conclusion? I hate disk images for storing files. If the container image gets corrupted, you cannot access ANY of your files. That is the reason why I will never use FleVault. At least, with regular Time Machine backups to external HDs, you can access your files manually, but with the sparsebundles… also, it sort of sucks that there is no guarantee of integrity on said sparsebundles. Finally, if you have a problem, you will have to be patient and let the processes take their time, which might be hours.

Oh, by the way, as indicated in the post I linked to, I tried using DiskWarrior, which is THE best disk repair tool out there, and which saved me quite a number of times (I bought it back in the days of the dreaded “The Thing” bug in OS9). But this time, it would crash silently after a few minutes of checking the sparsbundle…)

 

This entry was posted on Thursday, May 29th, 2008 at 10:49 CEST and is filed under Apple talk, Rants & Raves, Software. You can follow any responses to this entry through the RSS 2.0 feed. You can leave a response, or trackback from your own site.