PDA

View Full Version : SuperDuper error message


badlydrawnboy
04-30-2006, 03:37 PM
After using SuperDuper flawlessly for many months, I received the following error message this morning (twice) while doing my routine backup:

| 11:22:11 AM | Info | /Volumes/Lovebox/Users
| 11:23:51 AM | Info | WARNING: Caught I/O exception(5): Input/output error
| 11:23:51 AM | Info | WARNING: Source: /Volumes/Lovebox/Users/kavio/Pictures/Aperture Library.aplibrary/Home .approject/AP.Minis, lstat(): 0
| 11:23:51 AM | Info | WARNING: Target: /Volumes/Lovebox Backup 1/Users/kavio/Pictures/Aperture Library.aplibrary/Home .approject/AP.Minis, lstat(): 0
| 11:23:51 AM | Info | Attempting to copy file using copyfile().
| 11:23:51 AM | Info | Attempting to copy file using ditto.
| 11:23:53 AM | Error | SDCopy: Failed to recover from copy error for file /Volumes/Lovebox/Users/kavio/Pictures/Aperture Library.aplibrary/Home .approject/AP.Minis: Operation not supported

I don't know what to make of this. Can anyone help?

Thanks!

dnanian
04-30-2006, 03:43 PM
It looks like the destination volume had/is having a problem. Try restarting your Mac, then repairing the destination with Disk Utility. (Use the buttons on the right side of the First Aid tab -- don't repair permissions.)

If that doesn't help, we'll have to try to determine where the error is by looking at your system log. It might be on the source...

badlydrawnboy
04-30-2006, 04:18 PM
Oops, I might have blown it. Before reading this message I did repair the disk as you suggested but I also repaired permissions.

Here's the full log below. I just repaired permissions and did maintenance on the source (using Onyx), and tried backing up again, but still no luck. I see that the bad file descriptor is related to an image file in my Aperture library (Apple's professional photo editor).

Thanks again for your help.

| 12:08:59 PM | Info | SuperDuper!, 2.1 (77), path: /Volumes/Lovebox/Applications/SuperDuper!.app, Mac OS 10.4.6 build 8I127 (ppc)
| 12:08:59 PM | Info | Started on Sun, Apr 30, 2006 at 12:08 PM
| 12:08:59 PM | Info | Source Drive: Lovebox, mount: /Volumes/Lovebox, device: WDC WD1600JS-41MVB1, interconnect: Internal ATA, file system: "Journaled HFS+", OS: 10.4.6 (8I127), capacity: 148.93 GB, used: 85.54 GB, directories: 71773, files: 308516, ejectable: NO, ACLs: Disabled
| 12:08:59 PM | Info | Target Drive: Lovebox Backup, mount: /Volumes/Lovebox Backup 2, device: WDC FireWire/USB2.0, interconnect: External FireWire, file system: "Journaled HFS+", OS: 10.4.6 (8I127), capacity: 111.67 GB, used: 88.44 GB, directories: 72548, files: 310565, ejectable: NO, ACLs: Disabled
| 12:08:59 PM | Info | Copy Mode : Smart Update
| 12:08:59 PM | Info | Copy Script : Backup - all files.dset
| 12:08:59 PM | Info | Transcript : BuildTranscript.plist
| 12:09:00 PM | Info | PHASE: 1. Prepare to Copy Files
| 12:09:00 PM | Info | ...ACTION: Preparing Lovebox
| 12:09:00 PM | Info | ......COMMAND => Verifying the integrity of volinfo.database
| 12:09:00 PM | Info | volinfo.database OK
| 12:09:00 PM | Info | ......COMMAND => Enabling permissions on Lovebox
| 12:09:00 PM | Info | Refreshing Disk Arbitration ...
| 12:09:00 PM | Info | ......COMMAND => Verifying that permissions are enabled for Lovebox
| 12:09:00 PM | Info | Permissions on '/Volumes/Lovebox' are enabled.
| 12:09:00 PM | Info | ...ACTION: Repairing permissions on Lovebox
| 12:09:00 PM | Info | ......COMMAND => Repairing permissions on Lovebox
| 12:09:04 PM | Info | parent directory ./Users/Shared/SC Info does not exist
| 12:09:22 PM | Info | Started verify/repair permissions on disk disk1s3 Lovebox
| 12:09:22 PM | Info | Determining correct file permissions.
| 12:09:22 PM | Info | The privileges have been verified or repaired on the selected volume
| 12:09:22 PM | Info | Verify/repair finished permissions on disk disk1s3 Lovebox
| 12:09:22 PM | Info | ...ACTION: Preparing Lovebox Backup
| 12:09:22 PM | Info | ......COMMAND => Enabling permissions on Lovebox Backup
| 12:09:22 PM | Info | Refreshing Disk Arbitration ...
| 12:09:22 PM | Info | ......COMMAND => Verifying that permissions are enabled for Lovebox Backup
| 12:09:22 PM | Info | Permissions on '/Volumes/Lovebox Backup 2' are enabled.
| 12:09:22 PM | Info | ......COMMAND => Verifying that Lovebox Backup ACL support matches Lovebox
| 12:09:22 PM | Info | ......COMMAND => Disabling Spotlight search indexing on Lovebox Backup
| 12:09:22 PM | Info | PHASE: 2. Copy Files
| 12:09:22 PM | Info | ...ACTION: Copying files from Lovebox to Lovebox Backup
| 12:09:22 PM | Info | ......COMMAND => Cloning Lovebox to Lovebox Backup
| 12:09:22 PM | Info | Copying different files with delete using script: /Users/kavio/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 12:09:23 PM | Info | Loading 19 commands from copy script /Volumes/Lovebox/Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system temporary files.dset
| 12:09:23 PM | Info | Loading 6 commands from copy script /Volumes/Lovebox/Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system cache files.dset
| 12:09:23 PM | Info | Loading 1 commands from copy script /Volumes/Lovebox/Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Norton FileSaver files.dset
| 12:09:23 PM | Info | Loading 2 commands from copy script /Volumes/Lovebox/Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Spotlight search index.dset
| 12:09:23 PM | Info | Loading 0 commands from copy script /Users/kavio/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 12:09:23 PM | Info | /Volumes/Lovebox
| 12:09:26 PM | Info | /Volumes/Lovebox/bin
| 12:09:26 PM | Info | /Volumes/Lovebox/usr
| 12:09:34 PM | Info | /Volumes/Lovebox/.Spotlight-V100
| 12:09:34 PM | Info | Ignoring /Volumes/Lovebox/.Spotlight-V100/_IndexPolicy.plist
| 12:09:34 PM | Info | Ignoring /Volumes/Lovebox/.Spotlight-V100/.store.db
| 12:09:34 PM | Info | Ignoring /Volumes/Lovebox/.Spotlight-V100/_exclusions.plist
| 12:09:34 PM | Info | Ignoring /Volumes/Lovebox/.Spotlight-V100/.journalHistoryLog
| 12:09:34 PM | Info | Ignoring /Volumes/Lovebox/.Spotlight-V100/_rules.plist
| 12:09:34 PM | Info | Ignoring /Volumes/Lovebox/.Spotlight-V100/ContentIndex.db
| 12:09:34 PM | Info | Ignoring /Volumes/Lovebox/.Spotlight-V100/store.db
| 12:09:34 PM | Info | /Volumes/Lovebox/.Trashes
| 12:09:34 PM | Info | /Volumes/Lovebox/Users
| 12:10:21 PM | Info | WARNING: Caught I/O exception(5): Input/output error
| 12:10:21 PM | Info | WARNING: Source: /Volumes/Lovebox/Users/kavio/Pictures/Aperture Library.aplibrary/Jada.approject/AP.Minis, lstat(): 0
| 12:10:21 PM | Info | WARNING: Target: /Volumes/Lovebox Backup 2/Users/kavio/Pictures/Aperture Library.aplibrary/Jada.approject/AP.Minis, lstat(): 0
| 12:10:21 PM | Info | Attempting to copy file using copyfile().
| 12:10:22 PM | Info | Attempting to copy file using ditto.
| 12:10:22 PM | Error | SDCopy: Failed to recover from copy error for file /Volumes/Lovebox/Users/kavio/Pictures/Aperture Library.aplibrary/Jada.approject/AP.Minis: Bad file descriptor

dnanian
04-30-2006, 04:25 PM
It certainly looks like that file is bad. You might want to boot from your Tiger install DVD and run Disk Utility from the Installer menu (the bold one that says "Installer" next to the Apple menu at the top of the screen). Then, use the First Aid tab to repair the drive, again using the buttons on the right (NOT Repair Permissions on the left). Repeat until no problems are found, then boot back and try again.

If that doesn't help, I'd suggest going through the Troubleshooting steps in the User's Guide, focusing on the Aperture library. It's going to be a little hard to do, because the library itself is a bundle, and has stuff hidden inside it. (I also don't know what the "AP.Minis" file actually does, so I'm reluctant to suggest deleting it -- but you might want to navigate to it and try to *duplicate* it, should the repair above fail, to see if Finder can read it...)

badlydrawnboy
04-30-2006, 11:14 PM
Perhaps the problems are deeper than they seemed. I tried rebooting from the external HD. It starts up fine, but then when I open Disk Utility and try to repair the HD of my boot drive, I get an error message telling me it couldn't unmount the drive.

Then I tried starting up from the Tiger OS X CD. Four times, four "kernel panics" (I think this is what it is... text streaming across the screen and that message telling me I need to restart the computer). I can't figure out what to do now because I can't repair the disk using the OS X CD or an external HD & Disk Utility.

Any ideas?

dnanian
05-01-2006, 12:32 AM
I think I suggested booting from your OSX DVD, not the external drive -- unfortunately, neither seems to have worked.

Note that if your drive is named differently than the source, it's quite possible that aliases are resolving to the source, rather than the backup.

So, try booting back to the original drive, then name the backup the same. Then, boot from it and see if it'll unmount properly.

(Very strange you got Kernel Panics simply booting from your OSX DVD. That really implies there's something quite wrong with your system, or you did it with a large number of misbehaving peripherals attached...)

badlydrawnboy
05-01-2006, 10:06 AM
Dave,

Thanks again for your help - I really appreciate it. It does appear there's a *serious* problem with my system, because I tried both of your suggestions (renaming the external HD as my internal, restarting from the OS X DVD with no peripherals attached) and Disk Utility still can't unmount the drive and I still get kernel panics with the OS X DVD.

I probably should have mentioned this earlier, but I'm running a Sandbox. I actually have two internal HDs in my G5 tower. One is a Sandbox (which seems to be running fine and I was able to unmount it when booted from the original drive), the other is the original drive. Does this change anything?

Strangest of all, I had just updated the original drive from the Sandbox prior to discovering this problem with the original drive.

????

Thanks,
Chris

dnanian
05-01-2006, 10:12 AM
When you indicate that you're booting from the external, is the external a Sandbox or a full backup? If a Sandbox, you can't unmount the internal, because lots of things are shared.

Here's what I'd do at this point: get some drive you can boot from, not your backup, and install OSX on it, straight up. Then, use that to try to repair. The problem, of course, is that if your system is panicking when you simply start up from the DVD, there's no way to install anything... so, disconnect ALL peripherals and remove any 3rd party memory before the attempt.

You really need to be able to boot from the DVD without crashing, Chris... if you can't, I think it's likely you'll need to visit your local Apple Genius and/or get the Mac serviced.

badlydrawnboy
05-01-2006, 10:52 AM
Dave,

I was able to unmount the original drive by renaming it and booting from an external HD. I ran Disk Utility on the original drive, but no repairs were necessary. I then ran Disk Warrior and some minor changes were made to the directory. Then I restarted to the Sandbox.

At this point, I again tried restarting to the OSX DVD. And again, I got a kernel panic. This doesn't make any sense to me. The original drive appears to be fine, the Sandbox appears to be fine, but I can't start-up from the DVD.

I suppose I'll have to call Apple.

In the meantime, at the beginning of this post you cautioned me NOT to repair permissions on the original drive using Disk Utility. Why is that? I've been doing that routinely as part of my system maintenance (every two weeks or so I restart from an external HD and repair permissions on both the Sandbox and original HD using Disk Utility). Is this a bad idea?

Thanks,
Chris

dnanian
05-01-2006, 10:56 AM
Well, repairing permissions too much is a common problem, but that's not what I was pointing out. Rather, since there are two types of "repair", I wanted to make sure you were repairing the disk structure, as opposed to permissions.

badlydrawnboy
05-01-2006, 11:21 AM
After doing the drive repair and directory rebuilding I figured I'd try backing up the original HD to the external (which is what I was trying to do when this all started). Just a short time after starting the "smart update", the external drive gets unmounted and this error came up (below).

I'm not even sure what to say when I call Apple?? Disk Utility didn't reveal any problems, my computer seems to be running properly... but I'm not able to back it up using SuperDuper, and I'm not able to start-up from the OSX DVD. I suspect they'll just tell me to contact the software developer (you) on the backup issue because I don't imagine they know much about SuperDuper.

Here's the log:
| 07:12:06 AM | Info | Did not COPY shared-item /Volumes/Lovebox/private/tftpboot/private/tftpboot because it would have overwritten the original
| 07:12:09 AM | Info | Ignoring /Volumes/Lovebox/private/var/db/volinfo.database
| 07:12:09 AM | Info | Ignoring /Volumes/Lovebox/private/var/db/BootCache.playlist
| 07:12:41 AM | Info | WARNING: Caught I/O exception(5): Input/output error
| 07:12:41 AM | Info | WARNING: Source: /Volumes/Lovebox/private/var/log/daily.out, lstat(): 0
| 07:12:41 AM | Info | WARNING: Target: /Volumes/Lovebox Backup 3/private/var/log/daily.out, lstat(): 0
| 07:12:41 AM | Info | Attempting to copy file using copyfile().
| 07:12:41 AM | Info | Attempting to copy file using ditto.
| 07:12:41 AM | Error | SDCopy: Failed to recover from copy error for file /Volumes/Lovebox/private/var/log/daily.out:

dnanian
05-01-2006, 11:51 AM
If the drive unmounted, your Mac isn't running properly. The external drive, or the internal FireWire subsystem, is failing.

What I'd do is resolve the DVD boot problem with Apple. No need to mention the whole backup thing -- just focus on their explicit responsibility: your computer won't boot from the DVD without crashing.

badlydrawnboy
05-01-2006, 04:39 PM
Dave,

I spoke with Apple. We reset the nvram and I was able to start-up from the OSX DVD. Repaired disk, but no repairs were necessary. Repaired permissions, and a lot repairs were made there.

Tried backing up to the external HD and got the same error message and forced unmount. Then I pulled out another external HD and erased it, then had SuperDuper do an "erase and backup all files" to that drive. Worked fine.

So I'm guessing this means there's some problem with the first external HD or perhaps the backup/file structure. I guess I'll try erasing that (now that I've got another backup of my original HD) and try backing up from scratch instead of a "Smart Update".

Thanks again for all of your help tracking this down.

Chris

dnanian
05-01-2006, 05:10 PM
Well, that's good, at least!

So -- yeah, it certainly seems like that external drive is having problems. Usually, when a disk unmounts like that, it's because the drive is hitting a bad sector, and it stops communicating with the OS. Definitely erase *and* zero the drive, and give it a fresh backup.

badlydrawnboy
05-01-2006, 07:57 PM
Okay, last message here Dave... (I hope!)

I zeroed the external HD. Mounted it and tried an "erase, then copy". Very shortly into the process, it got unmounted again. Error message below.

Is my drive fried? Anything you know of I can try?

Thanks,
Chris

| 03:53:56 PM | Info | SuperDuper!, 2.1 (77), path: /Volumes/Lovebox/Applications/SuperDuper!.app, Mac OS 10.4.6 build 8I127 (ppc)
| 03:53:56 PM | Info | Started on Mon, May 1, 2006 at 3:53 PM
| 03:53:56 PM | Info | Source Drive: Lovebox, mount: /Volumes/Lovebox, device: WDC WD1600JS-41MVB1, interconnect: Internal ATA, file system: "Journaled HFS+", OS: 10.4.6 (8I127), capacity: 148.93 GB, used: 85.65 GB, directories: 71967, files: 310924, ejectable: NO, ACLs: Disabled
| 03:53:56 PM | Info | Target Drive: Backup, mount: /Volumes/Backup, device: WDC FireWire/USB2.0, interconnect: (null), file system: "Journaled HFS+", OS: N/A, capacity: 111.67 GB, used: 0.05 GB, directories: 4, files: 8, ejectable: NO, ACLs: Disabled
| 03:53:56 PM | Info | Copy Mode : Erase, then copy files
| 03:53:56 PM | Info | Copy Script : Backup - all files.dset
| 03:53:56 PM | Info | Transcript : BuildTranscript.plist
| 03:53:56 PM | Info | PHASE: 1. Prepare to Copy Files
| 03:53:56 PM | Info | ...ACTION: Preparing Lovebox
| 03:53:56 PM | Info | ......COMMAND => Verifying the integrity of volinfo.database
| 03:53:56 PM | Info | volinfo.database OK
| 03:53:56 PM | Info | ......COMMAND => Enabling permissions on Lovebox
| 03:53:56 PM | Info | Refreshing Disk Arbitration ...
| 03:53:56 PM | Info | ......COMMAND => Verifying that permissions are enabled for Lovebox
| 03:53:56 PM | Info | Permissions on '/Volumes/Lovebox' are enabled.
| 03:53:56 PM | Info | ...ACTION: Erasing Backup
| 03:53:56 PM | Info | ......COMMAND => Preserving Backup UUID
| 03:53:56 PM | Info | BD9490E45D63DA03
| 03:53:56 PM | Info | ......COMMAND => Preserving spotlight indexing state
| 03:53:56 PM | Info | ......COMMAND => Erasing Backup
| 03:54:03 PM | Info | ......COMMAND => Restoring Backup UUID (BD9490E45D63DA03)
| 03:54:04 PM | Info | BD9490E45D63DA03
| 03:54:04 PM | Info | ......COMMAND => Restoring Spotlight search indexing state on Backup
| 03:54:04 PM | Info | /Volumes/Backup:
| 03:54:04 PM | Info | Indexing enabled for volume.
| 03:54:04 PM | Info | Indexing enabled on Backup
| 03:54:04 PM | Info | ...ACTION: Preparing Backup
| 03:54:04 PM | Info | ......COMMAND => Enabling permissions on Backup
| 03:54:04 PM | Info | Refreshing Disk Arbitration ...
| 03:54:04 PM | Info | ......COMMAND => Verifying that permissions are enabled for Backup
| 03:54:04 PM | Info | Permissions on '/Volumes/Backup' are enabled.
| 03:54:04 PM | Info | ......COMMAND => Verifying that Backup ACL support matches Lovebox
| 03:54:04 PM | Info | ......COMMAND => Disabling Spotlight search indexing on Backup
| 03:54:04 PM | Info | PHASE: 2. Copy Files
| 03:54:04 PM | Info | ...ACTION: Copying files from Lovebox to Backup
| 03:54:04 PM | Info | ......COMMAND => Cloning Lovebox to Backup
| 03:54:04 PM | Info | Copying all files using script: /Users/kavio/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 03:54:04 PM | Info | Loading 19 commands from copy script /Volumes/Lovebox/Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system temporary files.dset
| 03:54:04 PM | Info | Loading 6 commands from copy script /Volumes/Lovebox/Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system cache files.dset
| 03:54:04 PM | Info | Loading 1 commands from copy script /Volumes/Lovebox/Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Norton FileSaver files.dset
| 03:54:04 PM | Info | Loading 2 commands from copy script /Volumes/Lovebox/Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Spotlight search index.dset
| 03:54:04 PM | Info | Loading 0 commands from copy script /Users/kavio/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 03:54:04 PM | Info | /Volumes/Lovebox
| 03:54:37 PM | Info | /Volumes/Lovebox/usr
| 03:54:37 PM | Info | WARNING: Caught I/O exception(5): Input/output error
| 03:54:37 PM | Info | WARNING: Source: /Volumes/Lovebox/usr/sbin/kdb5_util, lstat(): 0
| 03:54:37 PM | Info | WARNING: Target: /Volumes/Backup/usr/sbin/kdb5_util, lstat(): 0
| 03:54:37 PM | Info | Attempting to copy file using copyfile().
| 03:54:37 PM | Info | Attempting to copy file using ditto.
| 03:54:37 PM | Error | ditto: /Volumes/Backup/usr/sbin/kdb5_util: Device not configured
| 03:54:37 PM | Error | SDCopy: Failed to recover from copy error for file /Volumes/Lovebox/usr/sbin/kdb5_util: Operation not supported
| 03:54:37 PM | Error | ****FAILED****: result=256 errno=0 (Unknown error: 0)

dnanian
05-01-2006, 08:10 PM
Is this the new drive, or the original one? If you've switched out the drive itself, I'd expect the case is the problem.

badlydrawnboy
05-01-2006, 10:17 PM
It's an old (two or three years?) Western Digital 150G Firewire. It came in an enclosure/case and I haven't touched it or made any modifications. So it's the original one.

dnanian
05-01-2006, 10:42 PM
OK. Well... I think it might be time to retire it, or at least replace the drive in the mechanism to see if it's the drive or case.

bhavens
05-03-2006, 10:42 PM
I had this exact same problem. But mine showed an error on different files each time that I tried a backup. I tested each of the files that had errors and they were all fine. I even replaced them with backups from other drives just for safety sake. And they would error out again, although sometimes it would be different files again. None of the error listed files were actually bad. They were all fine. I see a ton of messages in my syslog when running SuperDuper, though. I get this error:

/Applications/SuperDuper!.app/Contents/MacOS/SDCopy: error processing extended attributes: Cannot allocate memory

Hundreds of messages in the log. Maybe you can help out with what that is all about.

Anyway, I ended up sending my external drive to the manufacturer and they told me that there was nothing wrong with the drive but they replaced it for me anyway. So I'm running SuperDuper again right now on my drive (haven't changed anything on my internal source drive. So far, so good. It's copying but I'm getting the syslog errors. Also, the copies worked fine for a couple of months just like yours and then they just stopped with the I/O errors. I'm wondering if there is a bug in the code somewhere that's causes the error. Very weird that it's happening. I love the program and REALLY would like to get this fixed. But I'm concerned that the errors will start up again. Thanks for your help Dave. Hope we can get it fixed.

dnanian
05-03-2006, 11:16 PM
The syslog error is known, and is discussed elsewhere on the forums. It's a diagnostic produced by an OSX API, at a warning level.

We've figured out a way to work around the problem, and there'll be a fix in the next update of SD. It doesn't have anything to do with the errors, which were very likely caused by a bad destination drive. (As described in the Troubleshooting section, when it moves around, or the file on the source is OK, it's a problem with the destination.)

Hope that helps...

bhavens
05-04-2006, 12:31 AM
....(As described in the Troubleshooting section, when it moves around, or the file on the source is OK, it's a problem with the destination.)

Well, for mine at least, according to the manufacturer, my drive was fine. They could find no issues whatever with the drive. But since I insisted, they replaced it anyway. I'll let you know if the I/O errors start up again. Thanks.

dnanian
05-04-2006, 08:21 AM
Well -- it wasn't, though. Otherwise, the problems would have continued with the new drive! :)