SD! Failures

[Nick]

The failures began last night: About 75% of the way through, SD! would simply stall. After an hour of waiting, I'd then press the "stop" button, get the usual "SD! ain't done yet...you sure you want to stop?" message. I'd say "yes," and that would be it....except that although it stopped, it remained open, and I had to either quit from within SD! itself, or force quit.

The only thing that caught my attention as being a bit "odd" was that although the SD! window indicates the usual:

---
What's going to happen?

Pressing "Copy Now" will use "Backup - all files" to copy Nick's HD to Nick's HD Clone ..."
----

the top portion indicates:

---
Copy Nick's HD to Nick's HD Clone 1
---

whereas in the past, I'm certain it simply said:

---
Copy Nick's HD to Nick's HD Clone
---

When I checked with DU, I found that the volume indeed had what I believe is a new "mount point":

Mount Point : /Volumes/Nick's HD Clone 1

(I don't know whether this apparent mount point change is significant or meaningful, but I though it worth mentioning.)

[Nick]

BTW: After the first failure, most of the SD! logs seemed to have vanished—only a handful from last month showed up. Subsequent failures didn't seem to suffer from that apparent loss.

FWIW, here's a copy of the most-recent log:

-----------
| 09:22:02 AM | Info | SuperDuper!, 2.6.2 (87), path: /Applications/SuperDuper!.app, Mac OS 10.5.8 build 9L31a (i386)
| 09:22:02 AM | Info | Started on Fri, Dec 11, 2009 at 9:22 AM
| 09:22:02 AM | Info | Source Volume: Nick's HD, mount: /, device: /dev/disk0s2, media: Hitachi HDP725032GLA380, interconnect: Internal SATA, file system: "Journaled HFS+", OS: 10.5.8 (9L31a), capacity: 297.77 GiB, used: 244.70 GiB, directories: 103654, files: 1075231, ejectable: NO, ACLs: Enabled
| 09:22:02 AM | Info | Target Volume: Nick's HD Clone, mount: /Volumes/Nick's HD Clone 1, device: /dev/disk4s5, media: LaCie d2 quadra, interconnect: External FireWire, file system: "Journaled HFS+", OS: 10.5.8 (9L31a), capacity: 348.30 GiB, used: 241.95 GiB, directories: 103251, files: 1076029, ejectable: YES, ACLs: Enabled
| 09:22:02 AM | Info | Copy Mode : Smart Update
| 09:22:02 AM | Info | Copy Script : Backup - all files.dset
| 09:22:02 AM | Info | Transcript : BuildTranscript.plist
| 09:22:02 AM | Info | PHASE: 1. Prepare to Copy Files
| 09:22:02 AM | Info | ...ACTION: Preparing Nick's HD
| 09:22:02 AM | Info | ......COMMAND => Verifying the integrity of volinfo.database
| 09:22:02 AM | Info | volinfo.database OK
| 09:22:02 AM | Info | ......COMMAND => Enabling permissions on Nick's HD
| 09:22:03 AM | Info | Refreshing Disk Arbitration ...
| 09:22:03 AM | Info | ......COMMAND => Verifying that permissions are enabled for Nick's HD
| 09:22:03 AM | Info | Permissions on '/' are enabled.
| 09:22:03 AM | Info | ...ACTION: Preparing Nick's HD Clone
| 09:22:03 AM | Info | ......COMMAND => Enabling permissions on Nick's HD Clone
| 09:22:03 AM | Info | Refreshing Disk Arbitration ...
| 09:22:03 AM | Info | ......COMMAND => Verifying that permissions are enabled for Nick's HD Clone
| 09:22:03 AM | Info | Permissions on '/Volumes/Nick's HD Clone 1' are enabled.
| 09:22:03 AM | Info | ......COMMAND => Verifying that Nick's HD Clone ACL support matches Nick's HD
| 09:22:03 AM | Info | ...ACTION: Preserving Spotlight state on Nick's HD Clone
| 09:22:03 AM | Info | ......COMMAND => Disabling Spotlight search indexing on Nick's HD Clone
| 09:22:03 AM | Info | PHASE: 2. Copy Files
| 09:22:03 AM | Info | ...ACTION: Copying files from Nick's HD to Nick's HD Clone using Smart Update
| 09:22:03 AM | Info | ......COMMAND => Cloning Nick's HD to Nick's HD Clone
| 09:22:03 AM | Info | Copying copy files with delete using script: /Users/Nick/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 09:22:04 AM | Info | Loading 27 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system temporary files.dset
| 09:22:04 AM | Info | Loading 6 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system cache files.dset
| 09:22:04 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Norton FileSaver files.dset
| 09:22:04 AM | Info | Loading 2 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Google Desktop Index files.dset
| 09:22:04 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude iTunes Temporary files.dset
| 09:22:04 AM | Info | Loading 0 commands from copy script /Users/Nick/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 09:22:07 AM | Info | /
| 09:22:07 AM | Info | /.vol
| 09:22:07 AM | Info | Ignoring /.vol
| 09:22:07 AM | Info | /cores
| 09:22:07 AM | Info | /Network
| 09:22:07 AM | Info | /Copies of Backups
| 09:23:07 AM | Info | /bin
| 09:23:07 AM | Info | /System
| 09:24:01 AM | Info | /private
| 09:24:01 AM | Info | Ignoring /private/var/folders/-H
| 09:24:01 AM | Info | Ignoring /private/var/folders/Pi
| 09:24:01 AM | Info | Ignoring /private/var/folders/zz
| 09:24:04 AM | Info | Ignoring /private/var/vm/swapfile0
| 09:24:04 AM | Info | Ignoring /private/var/db/BootCache.playlist
| 09:24:04 AM | Info | Ignoring /private/var/db/volinfo.database
| 09:24:04 AM | Info | Ignoring /private/var/run/usbmuxd
| 09:24:04 AM | Info | Ignoring /private/var/run/syslog
| 09:24:04 AM | Info | Ignoring /private/var/run/mDNSResponder
| 09:24:04 AM | Info | Ignoring /private/var/run/cupsd
| 09:24:04 AM | Info | Ignoring /private/var/run/asl_input
| 09:24:04 AM | Info | Ignoring /private/var/run/syslog.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/configd.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/virusbarrierl.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/diskarbitrationd.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/DirectoryService.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/mach.sym
| 09:24:04 AM | Info | Ignoring /private/var/run/netupdated.32
| 09:24:04 AM | Info | Ignoring /private/var/run/mds.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/com.apple.blued.launchd
| 09:24:04 AM | Info | Ignoring /private/var/run/automount.initialized
| 09:24:04 AM | Info | Ignoring /private/var/run/appfwd.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/vbsb.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/pcscd.pub
| 09:24:04 AM | Info | Ignoring /private/var/run/macaronid.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/vbsm.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/ntpd.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/utmpx
| 09:24:04 AM | Info | Ignoring /private/var/run/mds
| 09:24:04 AM | Info | Ignoring /private/var/run/pppconfd
| 09:24:04 AM | Info | Ignoring /private/var/run/portmap.socket
| 09:24:04 AM | Info | Ignoring /private/var/run/cron.pid
| 09:24:04 AM | Info | Ignoring /private/var/run/cups
| 09:24:04 AM | Info | Ignoring /private/var/run/.DSRunningSP1
| 09:24:04 AM | Info | Ignoring /private/var/tmp/.BlankFile
| 09:24:04 AM | Info | Ignoring /private/var/tmp/tmp.0.zqWEg8
| 09:24:04 AM | Info | Ignoring /private/var/tmp/tmp.1.1PW0iI
| 09:24:04 AM | Info | Ignoring /private/var/tmp/tmp.2.wfck3Q
| 09:24:04 AM | Info | Ignoring /private/var/tmp/com.apple.speech.synthesis.globals
| 09:24:04 AM | Info | Ignoring /private/var/tmp/BonjourPrinters.plist
| 09:24:04 AM | Info | Ignoring /private/var/tmp/Nick
| 09:24:04 AM | Info | Ignoring /private/var/tmp/launchd
| 09:24:04 AM | Info | Ignoring /private/var/tmp/mds
| 09:24:04 AM | Info | Ignoring /private/tmp/virusbarrier
| 09:24:04 AM | Info | Ignoring /private/tmp/MobileDevice.log
| 09:24:04 AM | Info | Ignoring /private/tmp/encyclopedia.shmsize
| 09:24:04 AM | Info | Ignoring /private/tmp/launchd-131.yXuKBy
| 09:24:04 AM | Info | Ignoring /private/tmp/launch-UHCz9x
| 09:24:04 AM | Info | Ignoring /private/tmp/launch-U2Rzai
| 09:24:04 AM | Info | Ignoring /private/tmp/launch-KaR1Be
| 09:24:04 AM | Info | Ignoring /private/tmp/icssuis501
| 09:24:04 AM | Info | Ignoring /private/tmp/ics217
| 09:24:04 AM | Info | Ignoring /private/tmp/target395.indexState
| 09:24:04 AM | Info | Ignoring /Desktop DF
| 09:24:04 AM | Info | Ignoring /Desktop DB
| 09:24:04 AM | Info | /Users
| 10:14:56 AM | Info | User terminated processing of transcript...
-----------

(Note that I actually didn't terminate SD! until after I received a dialog telling me that it had failed.)

[dnanian]

Yeah, that generally means that your backup drive failed and it remounted at a new location. Restart your Mac and see if it goes back to just the drive name without the 1.

[Nick]

Originally Posted by dnanian

Yeah, that generally means that your backup drive failed and it remounted at a new location. Restart your Mac and see if it goes back to just the drive name without the 1.

I've had to do several hard restarts (via the power button) since then. I just checked with DU, and the mount point still has "1" appended to the volume's name.

[dnanian]

Hard restarts aren't good, Nick - you're clearly experiencing some hardware issues here. But you can use Finder's "Go To Folder" command to open

/Volumes

You can delete the folder you'll find with the name of the backup drive there, then restart your Mac.

[Nick]

Originally Posted by dnanian

Hard restarts aren't good, Nick - you're clearly experiencing some hardware issues here. But you can use Finder's "Go To Folder" command to open

/Volumes

You can delete the folder you'll find with the name of the backup drive there, then restart your Mac.

Nick's HD Clone 1 (looks like an alias) or Nick's HD Clone (which looks more like an actual folder)?

[dnanian]

Folder only. Don't delete any aliases.