SuperDuper! Failure

[Nick]

I have SD! scheduled to do a daily backup. The last one (early this morning) failed. I was able to retrieve information from the log, and it had a series of error entries:

...
...
...

| 01:17:59 AM | Info | /.Spotlight-V100
| 01:17:59 AM | Info | Preserving /.Spotlight-V100
| 01:17:59 AM | Info | Ignoring /Desktop DF
| 01:17:59 AM | Info | /Users
| 01:18:35 AM | Error | LOGGED EXCEPTION: NSAccessibilityException, reason: "AXEnabled" attribute unsupported by: <NSPanel: 0x1c9edfa0>, userInfo: {NSAccessibilityErrorCodeExceptionInfo = -25205;}
| 01:18:35 AM | Error | LOGGED EXCEPTION: NSAccessibilityException, reason: "AXChildren" attribute unsupported by: <_NSThemeCloseWidgetCell: 0x1ca034c0>, userInfo: {NSAccessibilityErrorCodeExceptionInfo = -25205;}
| 01:18:35 AM | Error | LOGGED EXCEPTION: NSAccessibilityException, reason: "AXChildren" attribute unsupported by: <_NSThemeWidgetCell: 0x1ca02140>, userInfo: {NSAccessibilityErrorCodeExceptionInfo = -25205;}
| 01:18:35 AM | Error | LOGGED EXCEPTION: NSAccessibilityException, reason: "AXChildren" attribute unsupported by: <_NSThemeWidgetCell: 0x1c9e4530>, userInfo: {NSAccessibilityErrorCodeExceptionInfo = -25205;}
| 01:18:35 AM | Error | LOGGED EXCEPTION: NSAccessibilityException, reason: "AXChildren" attribute unsupported by: <NSButtonCell: 0x1ca1ec10>, userInfo: {NSAccessibilityErrorCodeExceptionInfo = -25205;}
| 01:18:35 AM | Error | LOGGED EXCEPTION: NSAccessibilityException, reason: "AXChildren" attribute unsupported by: <NSButtonCell: 0x1c96a7c0>, userInfo: {NSAccessibilityErrorCodeExceptionInfo = -25205;}
| 01:18:35 AM | Error | LOGGED EXCEPTION: NSAccessibilityException, reason: "AXChildren" attribute unsupported by: <NSButtonCell: 0x1c962270>, userInfo: {NSAccessibilityErrorCodeExceptionInfo = -25205;}
| 01:18:35 AM | Error | LOGGED EXCEPTION: NSAccessibilityException, reason: "AXChildren" attribute unsupported by: <NSButtonCell: 0x1c928390>, userInfo: {NSAccessibilityErrorCodeExceptionInfo = -25205;}


An SD! failure has only happened to me a few times before, and it was the kind of thing that took care of itself after I rebooted and manually ran the backup. Today, rebooting didn't help. In fact, I found the iMac to be rather unresponsive while SD! was attempting to create its backup (the spinning beachball kept on appearing). After a short while, SD! seemed to stall after having run through what appeared to be approximately the same number of files (about 0.5 million), and I had to quit SD! I repeatedly attempted a manual backup (usually after rebooting), but each time the results were the same: SD! would stall, and I’d have to quit. The last time it happened (a short while ago) I checked the log, and found that SD! was stalling at about the same point in its activity; after about a half hour of no further activity, I quit SD!:

...
...
...

| 10:52:37 AM | Info | /.Spotlight-V100
| 10:52:37 AM | Info | Preserving /.Spotlight-V100
| 10:52:37 AM | Info | Ignoring /Desktop DF
| 10:52:37 AM | Info | /Users
| 11:24:36 AM | Info | User terminated processing of transcript...


I ran Disk Utility as well as TechTool Pro, and both drives (internal and external SD!) appeared to be fine.

Suggestions?

[Nick]

The very next scheduled backup just ran...and failed. Here is the content of the log (which went on for 458 letter-size pages!):

-----------------------------------------

| 01:15:28 AM | Info | SuperDuper!, 2.5 (84), path: /Applications/SuperDuper!/SuperDuper!.app, Mac OS 10.5.6 build 9G55 (i386)
| 01:15:28 AM | Info | Started on Thu, Jun 11, 2009 at 1:15 AM
| 01:15:28 AM | Info | Source Volume: Nick's HD, mount: /, device: /dev/disk0s2, media: Hitachi HDP725032GLA380, interconnect: Internal SATA, file system: "Journaled HFS+", OS: 10.5.6 (9G55), capacity: 297.77 GB, used: 243.77 GB, directories: 166345, files: 1367306, ejectable: NO, ACLs: Enabled
| 01:15:28 AM | Info | Target Volume: Nick's HD Clone, mount: /Volumes/Nick's HD Clone, device: /dev/disk4s5, media: LaCie d2 quadra, interconnect: External FireWire, file system: "Journaled HFS+", OS: 10.5.6 (9G55), capacity: 348.30 GB, used: 239.54 GB, directories: 163031, files: 1353813, ejectable: NO, ACLs: Enabled
| 01:15:28 AM | Info | Copy Mode : Smart Update
| 01:15:28 AM | Info | Copy Script : Backup - all files.dset
| 01:15:28 AM | Info | Transcript : BuildTranscript.plist
| 01:15:29 AM | Info | PHASE: 1. Prepare to Copy Files
| 01:15:29 AM | Info | ...ACTION: Preparing Nick's HD
| 01:15:29 AM | Info | ......COMMAND => Verifying the integrity of volinfo.database
| 01:15:29 AM | Info | volinfo.database OK
| 01:15:29 AM | Info | ......COMMAND => Enabling permissions on Nick's HD
| 01:15:29 AM | Info | Refreshing Disk Arbitration ...
| 01:15:29 AM | Info | ......COMMAND => Verifying that permissions are enabled for Nick's HD
| 01:15:29 AM | Info | Permissions on '/' are enabled.
| 01:15:29 AM | Info | ...ACTION: Preparing Nick's HD Clone
| 01:15:29 AM | Info | ......COMMAND => Enabling permissions on Nick's HD Clone
| 01:15:29 AM | Info | Refreshing Disk Arbitration ...
| 01:15:30 AM | Info | ......COMMAND => Verifying that permissions are enabled for Nick's HD Clone
| 01:15:30 AM | Info | Permissions on '/Volumes/Nick's HD Clone' are enabled.
| 01:15:30 AM | Info | ......COMMAND => Verifying that Nick's HD Clone ACL support matches Nick's HD
| 01:15:30 AM | Info | ...ACTION: Preserving Spotlight state on Nick's HD Clone
| 01:15:30 AM | Info | ......COMMAND => Disabling Spotlight search indexing on Nick's HD Clone
| 01:15:30 AM | Info | PHASE: 2. Copy Files
| 01:15:30 AM | Info | ...ACTION: Copying files from Nick's HD to Nick's HD Clone using Smart Update
| 01:15:30 AM | Info | ......COMMAND => Cloning Nick's HD to Nick's HD Clone
| 01:15:30 AM | Info | Copying copy files with delete using script: /Users/Nick/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 01:15:31 AM | Info | Loading 22 commands from copy script /Applications/SuperDuper!/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system temporary files.dset
| 01:15:31 AM | Info | Loading 6 commands from copy script /Applications/SuperDuper!/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system cache files.dset
| 01:15:31 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Norton FileSaver files.dset
| 01:15:31 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Google Desktop Index files.dset
| 01:15:31 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude iTunes Temporary files.dset
| 01:15:31 AM | Info | Loading 0 commands from copy script /Users/Nick/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 01:15:31 AM | Info | /
| 01:15:34 AM | Info | /.vol
| 01:15:34 AM | Info | Ignoring /.vol
| 01:15:34 AM | Info | /cores
| 01:15:34 AM | Info | /Network
| 01:15:34 AM | Info | /private
| 01:15:46 AM | Info | Ignoring /private/var/run/syslog.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/configd.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/DirectoryService.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/virusbarrierl.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/mach.sym
| 01:15:46 AM | Info | Ignoring /private/var/run/diskarbitrationd.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/com.apple.blued.launchd
| 01:15:46 AM | Info | Ignoring /private/var/run/mds.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/automount.initialized
| 01:15:46 AM | Info | Ignoring /private/var/run/macaronid.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/appfwd.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/pcscd.pub
| 01:15:46 AM | Info | Ignoring /private/var/run/ntpd.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/vbsb.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/mds
| 01:15:46 AM | Info | Ignoring /private/var/run/cron.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/vbsm.pid
| 01:15:46 AM | Info | Ignoring /private/var/run/utmpx
| 01:15:46 AM | Info | Ignoring /private/var/run/resolv.conf
| 01:15:46 AM | Info | Ignoring /private/var/run/cups
| 01:15:46 AM | Info | Ignoring /private/var/run/hdiejectd.pid
| 01:15:47 AM | Info | Ignoring /private/var/db/BootCache.playlist
| 01:15:47 AM | Info | Ignoring /private/var/db/volinfo.database
| 01:15:47 AM | Info | Ignoring /private/var/vm/swapfile0
| 01:15:47 AM | Info | Ignoring /private/var/vm/swapfile1
| 01:15:47 AM | Info | Ignoring /private/var/vm/swapfile2
| 01:15:47 AM | Info | Ignoring /private/var/vm/swapfile3
| 01:15:47 AM | Info | Ignoring /private/var/vm/swapfile4
| 01:15:47 AM | Info | Ignoring /private/var/vm/swapfile5
| 01:15:47 AM | Info | Ignoring /private/var/tmp/com.apple.speech.synthesis.globals
| 01:15:47 AM | Info | Ignoring /private/var/tmp/sh-thd-3636534418
| 01:15:47 AM | Info | Ignoring /private/var/tmp/krb5_RC56aaa
| 01:15:47 AM | Info | Ignoring /private/var/tmp/sh-thd-3655676680
| 01:15:47 AM | Info | Ignoring /private/var/tmp/krb5kdc_rcache
| 01:15:47 AM | Info | Ignoring /private/var/tmp/sh-thd-1223478919
| 01:15:47 AM | Info | Ignoring /private/var/tmp/sh-thd-1223478057
| 01:15:47 AM | Info | Ignoring /private/var/tmp/tmp.0.Q7UyzF.html
| 01:15:47 AM | Info | Ignoring /private/var/tmp/etilqs_vIjPKZG28aKOKHw
| 01:15:47 AM | Info | Ignoring /private/var/tmp/psOutput
| 01:15:47 AM | Info | Ignoring /private/var/tmp/launchd
| 01:15:47 AM | Info | Ignoring /private/var/tmp/mds
| 01:15:47 AM | Info | Ignoring /private/var/tmp/com.micromat.TechToolPro4.plist
| 01:15:47 AM | Info | Ignoring /private/tmp/virusbarrier
| 01:15:47 AM | Info | Ignoring /private/tmp/encyclopedia.shmsize
| 01:15:47 AM | Info | Ignoring /private/tmp/launchd-178.1i4N7j
| 01:15:47 AM | Info | Ignoring /private/tmp/launch-eP53fw
| 01:15:47 AM | Info | Ignoring /private/tmp/launch-RdOzin
| 01:15:47 AM | Info | Ignoring /private/tmp/launch-2ZnixA
| 01:15:47 AM | Info | Ignoring /private/tmp/amt.log
| 01:15:47 AM | Info | Ignoring /private/tmp/VBXAlertPID
| 01:15:47 AM | Info | Ignoring /private/tmp/hsperfdata_Nick
| 01:15:47 AM | Info | Ignoring /private/tmp/libswt-pi-carbon-3436.jnilib
| 01:15:47 AM | Info | Ignoring /private/tmp/libswt-carbon-3436.jnilib
| 01:15:47 AM | Info | Ignoring /private/tmp/libswt-cocoa-carbon-3436.jnilib
| 01:15:47 AM | Info | Ignoring /private/tmp/AZU11410.tmp
| 01:15:47 AM | Info | Ignoring /private/tmp/target.indexState
| 01:15:47 AM | Info | /.Spotlight-V100
| 01:15:47 AM | Info | Preserving /.Spotlight-V100
| 01:15:50 AM | Info | Ignoring /Desktop DF
| 01:15:50 AM | Info | /Users
| 01:18:32 AM | Info | Unable to create hard link from /Volumes/Nick's HD Clone/Users/Nick/Library/Safari/lock to (null)
| 01:18:32 AM | Info | Does not exist: (null)
| 01:18:32 AM | Info | Does not exist: (null)
•
•
•
•
•
(Repeats for over 450 pages!)
•
•
•
•
| 01:18:35 AM | Info | Does not exist: (null)
| 01:18:35 AM | Info | Does not exist: (null)
| 01:18:35 AM | Info | Does not exist: (null)
| 01:18:35 AM | Info | Does not exist: (null)
| 01:18:40 AM | Error | ****FAILED****: result=11 errno=22 (Unknown error: 0)

-----------------------------------------

I'm at a loss as to what's going on. All I know is that I no longer can use SD! to clone my drive (which makes me feel very vulnerable).


Can anyone please help?


TIA.

[dnanian]

Yes. The problem here is that you were running Safari while we were backing up, and it created (and deleted) that 'lock' file as we were copying (and deleted it out from under us).

Repeat the backup after quitting Safari and it should work fine.

[Nick]

Originally Posted by dnanian

Yes. The problem here is that you were running Safari while we were backing up, and it created (and deleted) that 'lock' file as we were copying (and deleted it out from under us).

Repeat the backup after quitting Safari and it should work fine.

Hi Dave. Thanks for responding (especially so early in the morning! ).

Well, I’ve often had apps running (including Safari) while SD! was creating backups, and never had a problem. And looking at the log from the initial SD! failure as well as the subsequent attempt to manually run SD! (see my initial post), there is no mention of Safari. (Moreover, as I was running into a lot of spinning beachballs, I specifically made sure I had quit all apps while attempting subsequent manual backups.)

Nevertheless, I did again try a manual backup, and pretty much had the same result: It stalled after about 0.5 million files; I waited a while (about 15 more minutes), and then quit. Here is the complete log:

-----------------------------------------------------------------------
| 10:19:54 AM | Info | SuperDuper!, 2.5 (84), path: /Applications/SuperDuper!/SuperDuper!.app, Mac OS 10.5.6 build 9G55 (i386)
| 10:19:54 AM | Info | Started on Thu, Jun 11, 2009 at 10:19 AM
| 10:19:54 AM | Info | Source Volume: Nick's HD, mount: /, device: /dev/disk0s2, media: Hitachi HDP725032GLA380, interconnect: Internal SATA, file system: "Journaled HFS+", OS: 10.5.6 (9G55), capacity: 297.77 GB, used: 243.82 GB, directories: 166343, files: 1367761, ejectable: NO, ACLs: Enabled
| 10:19:54 AM | Info | Target Volume: Nick's HD Clone, mount: /Volumes/Nick's HD Clone, device: /dev/disk4s5, media: LaCie d2 quadra, interconnect: External FireWire, file system: "Journaled HFS+", OS: 10.5.6 (9G55), capacity: 348.30 GB, used: 239.60 GB, directories: 163065, files: 1354044, ejectable: NO, ACLs: Enabled
| 10:19:54 AM | Info | Copy Mode : Smart Update
| 10:19:54 AM | Info | Copy Script : Backup - all files.dset
| 10:19:54 AM | Info | Transcript : BuildTranscript.plist
| 10:19:54 AM | Info | PHASE: 1. Prepare to Copy Files
| 10:19:54 AM | Info | ...ACTION: Preparing Nick's HD
| 10:19:54 AM | Info | ......COMMAND => Verifying the integrity of volinfo.database
| 10:19:55 AM | Info | volinfo.database OK
| 10:19:55 AM | Info | ......COMMAND => Enabling permissions on Nick's HD
| 10:19:55 AM | Info | Refreshing Disk Arbitration ...
| 10:19:55 AM | Info | ......COMMAND => Verifying that permissions are enabled for Nick's HD
| 10:19:55 AM | Info | Permissions on '/' are enabled.
| 10:19:55 AM | Info | ...ACTION: Preparing Nick's HD Clone
| 10:19:55 AM | Info | ......COMMAND => Enabling permissions on Nick's HD Clone
| 10:19:55 AM | Info | Refreshing Disk Arbitration ...
| 10:19:55 AM | Info | ......COMMAND => Verifying that permissions are enabled for Nick's HD Clone
| 10:19:55 AM | Info | Permissions on '/Volumes/Nick's HD Clone' are enabled.
| 10:19:55 AM | Info | ......COMMAND => Verifying that Nick's HD Clone ACL support matches Nick's HD
| 10:19:56 AM | Info | ...ACTION: Preserving Spotlight state on Nick's HD Clone
| 10:19:56 AM | Info | ......COMMAND => Disabling Spotlight search indexing on Nick's HD Clone
| 10:19:56 AM | Info | PHASE: 2. Copy Files
| 10:19:56 AM | Info | ...ACTION: Copying files from Nick's HD to Nick's HD Clone using Smart Update
| 10:19:56 AM | Info | ......COMMAND => Cloning Nick's HD to Nick's HD Clone
| 10:19:56 AM | Info | Copying copy files with delete using script: /Users/Nick/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 10:19:56 AM | Info | Loading 22 commands from copy script /Applications/SuperDuper!/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system temporary files.dset
| 10:19:56 AM | Info | Loading 6 commands from copy script /Applications/SuperDuper!/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system cache files.dset
| 10:19:56 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Norton FileSaver files.dset
| 10:19:56 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Google Desktop Index files.dset
| 10:19:56 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude iTunes Temporary files.dset
| 10:19:56 AM | Info | Loading 0 commands from copy script /Users/Nick/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 10:19:56 AM | Info | /
| 10:19:59 AM | Info | /.vol
| 10:19:59 AM | Info | Ignoring /.vol
| 10:19:59 AM | Info | /cores
| 10:19:59 AM | Info | /Network
| 10:19:59 AM | Info | /private
| 10:20:09 AM | Info | Ignoring /private/var/vm/swapfile0
| 10:20:09 AM | Info | Ignoring /private/var/vm/swapfile1
| 10:20:09 AM | Info | Ignoring /private/var/vm/swapfile2
| 10:20:09 AM | Info | Ignoring /private/var/vm/swapfile3
| 10:20:09 AM | Info | Ignoring /private/var/vm/swapfile4
| 10:20:09 AM | Info | Ignoring /private/var/vm/swapfile5
| 10:20:09 AM | Info | Ignoring /private/var/db/BootCache.playlist
| 10:20:09 AM | Info | Ignoring /private/var/db/volinfo.database
| 10:20:09 AM | Info | Ignoring /private/var/run/syslog.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/configd.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/DirectoryService.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/virusbarrierl.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/mach.sym
| 10:20:09 AM | Info | Ignoring /private/var/run/diskarbitrationd.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/com.apple.blued.launchd
| 10:20:09 AM | Info | Ignoring /private/var/run/mds.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/automount.initialized
| 10:20:09 AM | Info | Ignoring /private/var/run/macaronid.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/appfwd.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/pcscd.pub
| 10:20:09 AM | Info | Ignoring /private/var/run/ntpd.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/vbsb.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/mds
| 10:20:09 AM | Info | Ignoring /private/var/run/cron.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/vbsm.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/utmpx
| 10:20:09 AM | Info | Ignoring /private/var/run/cups
| 10:20:09 AM | Info | Ignoring /private/var/run/hdiejectd.pid
| 10:20:09 AM | Info | Ignoring /private/var/run/resolv.conf
| 10:20:09 AM | Info | Ignoring /private/var/tmp/com.apple.speech.synthesis.globals
| 10:20:09 AM | Info | Ignoring /private/var/tmp/sh-thd-3636534418
| 10:20:09 AM | Info | Ignoring /private/var/tmp/krb5_RC56aaa
| 10:20:09 AM | Info | Ignoring /private/var/tmp/sh-thd-3655676680
| 10:20:09 AM | Info | Ignoring /private/var/tmp/krb5kdc_rcache
| 10:20:09 AM | Info | Ignoring /private/var/tmp/sh-thd-1223478919
| 10:20:09 AM | Info | Ignoring /private/var/tmp/sh-thd-1223478057
| 10:20:09 AM | Info | Ignoring /private/var/tmp/tmp.0.Q7UyzF.html
| 10:20:09 AM | Info | Ignoring /private/var/tmp/etilqs_vIjPKZG28aKOKHw
| 10:20:09 AM | Info | Ignoring /private/var/tmp/psOutput
| 10:20:09 AM | Info | Ignoring /private/var/tmp/launchd
| 10:20:09 AM | Info | Ignoring /private/var/tmp/mds
| 10:20:09 AM | Info | Ignoring /private/var/tmp/com.micromat.TechToolPro4.plist
| 10:20:09 AM | Info | Ignoring /private/tmp/virusbarrier
| 10:20:09 AM | Info | Ignoring /private/tmp/encyclopedia.shmsize
| 10:20:09 AM | Info | Ignoring /private/tmp/launchd-178.1i4N7j
| 10:20:09 AM | Info | Ignoring /private/tmp/launch-eP53fw
| 10:20:09 AM | Info | Ignoring /private/tmp/launch-RdOzin
| 10:20:09 AM | Info | Ignoring /private/tmp/launch-2ZnixA
| 10:20:09 AM | Info | Ignoring /private/tmp/amt.log
| 10:20:09 AM | Info | Ignoring /private/tmp/VBXAlertPID
| 10:20:09 AM | Info | Ignoring /private/tmp/libswt-pi-carbon-3436.jnilib
| 10:20:09 AM | Info | Ignoring /private/tmp/libswt-carbon-3436.jnilib
| 10:20:09 AM | Info | Ignoring /private/tmp/libswt-cocoa-carbon-3436.jnilib
| 10:20:09 AM | Info | Ignoring /private/tmp/AZU11410.tmp
| 10:20:09 AM | Info | Ignoring /private/tmp/hsperfdata_Nick
| 10:20:09 AM | Info | Ignoring /private/tmp/target.indexState
| 10:20:09 AM | Info | /.Spotlight-V100
| 10:20:09 AM | Info | Preserving /.Spotlight-V100
| 10:20:12 AM | Info | Ignoring /Desktop DF
| 10:20:12 AM | Info | /Users
| 10:34:13 AM | Info | User terminated processing of transcript...
-----------------------------------------------------------------------

(continued...)

[Nick]

(...continued)

Now, being rather stubborn , I decided to try another manual run, but not quit if and when it stalled. This time it stalled as it did before (again, after about 0.5 million files). However, I decided to let it run, to see if SD! would eventually issue a failure notification. This time, after about a half hour being stalled, SD! resumed, and eventually completed a successful run. When I examined the log, it appeared to be identical to the previous log (the one above), except that after SD! resumed, there were (of course) additional entries:

-----------------------------------------------------------------------
| 01:33:37 PM | Info | SuperDuper!, 2.5 (84), path: /Applications/SuperDuper!/SuperDuper!.app, Mac OS 10.5.6 build 9G55 (i386)
| 01:33:37 PM | Info | Started on Thu, Jun 11, 2009 at 1:33 PM
•
•
•
•
(Same entries as previous log)
•
•
•
•
| 01:33:58 PM | Info | /.Spotlight-V100
| 01:33:58 PM | Info | Preserving /.Spotlight-V100
| 01:33:58 PM | Info | Ignoring /Desktop DF
| 01:33:58 PM | Info | /Users
| 02:01:39 PM | Info | Ignoring /Desktop DB
| 02:01:39 PM | Info | /Developer
| 02:03:39 PM | Info | /usr
| 02:04:09 PM | Info | /.TemporaryItems
| 02:04:09 PM | Info | Ignoring /.hotfiles.btree
| 02:04:09 PM | Info | /Copies of Backups
| 02:05:46 PM | Info | /bin
| 02:05:46 PM | Info | /System
| 02:07:01 PM | Info | /sbin
| 02:07:01 PM | Info | /Library
| 02:12:30 PM | Info | /.Trashes
| 02:12:30 PM | Info | /dev
| 02:12:30 PM | Info | /net
| 02:12:30 PM | Info | /home
| 02:12:30 PM | Info | /Applications
| 02:21:01 PM | Info | /Volumes
| 02:21:01 PM | Info | Ignoring /Volumes/.DS_Store
| 02:21:01 PM | Info | Ignoring /Volumes/TechTool Pro 4 DVD
| 02:21:01 PM | Info | Ignoring /Volumes/Mac OS X Install Disc 1
| 02:21:01 PM | Info | Ignoring /Volumes/DiskWarriorCD
| 02:21:01 PM | Info | Ignoring /Volumes/Mac OS X Install Disc 2
| 02:21:01 PM | Info | Ignoring /Volumes/.vbt5
| 02:21:01 PM | Info | Ignoring /Volumes/Nick's HD Clone
| 02:21:01 PM | Info | Ignoring /Volumes/Nick's HD
| 02:21:01 PM | Info | Ignoring /Volumes/CompUSA Western Digital
| 02:21:01 PM | Info | Ignoring /Volumes/Seagate Barracuda
| 02:21:01 PM | Info | Ignoring /Volumes/LaCie
| 02:21:01 PM | Info | Ignoring /Volumes/LaCie d2 Quadra
| 02:21:01 PM | Info | /.fseventsd
| 02:21:01 PM | Info | Preserving /.fseventsd
| 02:21:01 PM | Info | Evaluated 1527818 items occupying 242.91 GB (166348 directories, 1326844 files, 34626 symlinks)
| 02:21:01 PM | Info | Copied 27573 items totaling 12.25 GB (11904 directories, 15568 files, 101 symlinks)
| 02:21:01 PM | Info | Cloned 240.28 GB of data in 2842 seconds at an effective transfer rate of 86.58 MB/s
| 02:21:01 PM | Info | ......COMMAND => Resetting Custom Icon bit on Nick's HD Clone
| 02:21:01 PM | Info | PHASE: 3. After Successful Copy
| 02:21:01 PM | Info | ...ACTION: Making Nick's HD Clone bootable
| 02:21:01 PM | Info | ......COMMAND => Blessing OS X System Folder
| 02:21:02 PM | Info | Successfully blessed Mac OS X folder on Nick's HD Clone
| 02:21:02 PM | Info | ......COMMAND => Blessing OS 9 System Folder
| 02:21:02 PM | Info | Did not bless Mac OS 9 System Folder on Nick's HD Clone because it does not exist.
| 02:21:02 PM | Info | ...ACTION: Restoring Spotlight state on Nick's HD Clone
| 02:21:02 PM | Info | ......COMMAND => Restoring Spotlight search indexing state on Nick's HD Clone
| 02:21:02 PM | Info | Copy complete.
-----------------------------------------------------------------------

Any idea what may have been happening—i.e., why the scheduled SD! failed to begin with, why subsequent manual attempts “stalled,” why the next scheduled backup also failed, and why it seems to be working now (though I won’t know until the next scheduled backup whether everything is “back to normal”)?

Thanks.

Nick

[dnanian]

The one that failed with all the (null)s was definitely Safari:

| 01:18:32 AM | Info | Unable to create hard link from /Volumes/Nick's HD Clone/Users/Nick/Library/Safari/lock to (null)

That's because 'lock' was deleted out from under us.

The other issue is likely that it was copying a large file, somewhere in your Home folder...