Failed to mount sparse image... what does this mean?

[rithban]

I have a sparse image that resides on a pair of mirrored external 1TB LaCie drives. I manually run SD every night; the last action I take before leaving the computer.

I noticed this morning that last night (and now again today) SD is failing. It repairs permissions on the internal HD (the one being backed up), and fails when it tries to mount the sparse image.

I can double-click on the sparse image and mount it manually. (I unmount the sparse image before attempting to run SD again.)

This is very odd. Here's the log

- - - - - - - -

| 09:39:33 AM | Info | SuperDuper!, 2.1.4 (82), path: /Applications/SuperDuper!.app, Mac OS 10.4.10 build 8R2218 (i386)
| 09:39:33 AM | Info | Started on Mon, Aug 20, 2007 at 9:39 AM
| 09:39:33 AM | Info | Source Volume: InternalHD, mount: /, device: /dev/disk0s2, media: Hitachi HTS722020K9SA00, interconnect: Internal SATA, file system: "Journaled HFS+", OS: 10.4.10 (8R2218), capacity: 185.99 GB, used: 113.21 GB, directories: 122672, files: 596887, ejectable: NO, ACLs: Disabled
| 09:39:33 AM | Info | Target Image: /Volumes/backup/SuperDuper/balthasar-昨日.sparseimage, name: balthasar-昨日
| 09:39:33 AM | Info | Copy Mode : Smart Update
| 09:39:33 AM | Info | Copy Script : Backup - all files.dset
| 09:39:33 AM | Info | Transcript : BuildTranscript.plist
| 09:39:34 AM | Info | PHASE: 1. Prepare to Copy Files
| 09:39:34 AM | Info | ...ACTION: Preparing InternalHD
| 09:39:34 AM | Info | ......COMMAND => Verifying the integrity of volinfo.database
| 09:39:34 AM | Info | volinfo.database OK
| 09:39:34 AM | Info | ......COMMAND => Enabling permissions on InternalHD
| 09:39:34 AM | Info | Refreshing Disk Arbitration ...
| 09:39:37 AM | Info | ......COMMAND => Verifying that permissions are enabled for InternalHD
| 09:39:37 AM | Info | Permissions on '/' are enabled.
| 09:39:37 AM | Info | ...ACTION: Repairing permissions on InternalHD
| 09:39:37 AM | Info | ......COMMAND => Repairing permissions on InternalHD
| 09:40:29 AM | Info | Started verify/repair permissions on disk disk0s2 InternalHD
| 09:40:29 AM | Info | Determining correct file permissions.
| 09:40:29 AM | Info | The privileges have been verified or repaired on the selected volume
| 09:40:29 AM | Info | Verify/repair finished permissions on disk disk0s2 InternalHD
| 09:40:29 AM | Info | ...ACTION: Mounting balthasar-昨日
| 09:40:29 AM | Info | ......COMMAND => Preparing balthasar-昨日
| 09:40:29 AM | Info | ......COMMAND => Setting ownership and access modes for '/Volumes/backup/SuperDuper/balthasar-昨日.sparseimage'
| 09:40:29 AM | Info | ......COMMAND => Mounting balthasar-昨日
| 09:40:35 AM | Error | load_hdi: IOHDIXControllerArrivalCallback: timed out waiting for IOKit to finish matching.

[dnanian]

Try restarting your Mac, rithban. Typically, that'll correct the problem, which is due to a low-level issue in OSX's IOKit.

[rithban]

OK... that did the trick. Seems like every OS has a niggly in a library somewhere.

Hey Apple! What's the big deal, guys? Can't you write a measly million lines of code without messing up? Geez Looeez! :D :D :D

[dnanian]

Yeah, this is a weird one that only affects some users...

[rithban]

Doh!

I have a note here from some months ago about rebooting when encountering IOKit oddities.

I have so few problems with OS X (and Linux) that rebooting never comes to mind. (But when doing development work rebooting Windows is just part of a day's work.) Funny how the human brain works.

Thanks for the reminder! *blush*