Continuously failing on "/private/" folder

[mschirma]

Hello

I've been trying to make a full-disk bootable backup for over 2 days now, but SD consistently fails at the exact same folder. Occasionally it is a different file, but it is always in the /private/ folder. I've noticed that the problem occurs mostly in the /private/var/log ... folder.

Here is a log of the most recent failure:

| 09:52:43 AM | Info | SuperDuper!, 2.1.4 (82), path: /Applications/SuperDuper!.app, Mac OS 10.4.11 build 8S2167 (i386)
| 09:52:43 AM | Info | Started on Tue, Aug 11, 2009 at 9:52 AM
| 09:52:43 AM | Info | Source Volume: Macintosh HD, mount: /, device: /dev/disk0s2, media: WDC WD1600BEVS-00RST0, interconnect: Internal SATA, file system: "Journaled HFS+", OS: 10.4.11 (8S2167), capacity: 133.00 GB, used: 127.77 GB, directories: 127214, files: 566074, ejectable: NO, ACLs: Disabled
| 09:52:43 AM | Info | Target Volume: Macintosh HD, mount: /Volumes/Macintosh HD 1, device: /dev/disk1s2, media: WDC WD32 00BEVT-22ZCT0, interconnect: External USB, file system: "Journaled HFS+", OS: 10.4.11 (8S2167), capacity: 297.77 GB, used: 89.83 GB, directories: 89962, files: 362199, ejectable: NO, ACLs: Disabled
| 09:52:43 AM | Info | Copy Mode : Smart Update
| 09:52:43 AM | Info | Copy Script : Backup - all files.dset
| 09:52:43 AM | Info | Transcript : BuildTranscript.plist
| 09:52:43 AM | Info | PHASE: 1. Prepare to Copy Files
| 09:52:43 AM | Info | ...ACTION: Preparing Macintosh HD
| 09:52:43 AM | Info | ......COMMAND => Verifying the integrity of volinfo.database
| 09:52:44 AM | Info | volinfo.database OK
| 09:52:44 AM | Info | ......COMMAND => Enabling permissions on Macintosh HD
| 09:52:44 AM | Info | Refreshing Disk Arbitration ...
| 09:52:44 AM | Info | ......COMMAND => Verifying that permissions are enabled for Macintosh HD
| 09:52:44 AM | Info | Permissions on '/' are enabled.
| 09:52:44 AM | Info | ...ACTION: Preparing Macintosh HD
| 09:52:44 AM | Info | ......COMMAND => Enabling permissions on Macintosh HD
| 09:52:44 AM | Info | Refreshing Disk Arbitration ...
| 09:52:44 AM | Info | ......COMMAND => Verifying that permissions are enabled for Macintosh HD
| 09:52:44 AM | Info | Permissions on '/Volumes/Macintosh HD 1' are enabled.
| 09:52:44 AM | Info | ......COMMAND => Verifying that Macintosh HD ACL support matches Macintosh HD
| 09:52:44 AM | Info | ...ACTION: Preserving Spotlight state on Macintosh HD
| 09:52:44 AM | Info | ......COMMAND => Disabling Spotlight search indexing on Macintosh HD
| 09:52:44 AM | Info | PHASE: 2. Copy Files
| 09:52:44 AM | Info | ...ACTION: Copying files from Macintosh HD to Macintosh HD using Smart Update
| 09:52:44 AM | Info | ......COMMAND => Cloning Macintosh HD to Macintosh HD
| 09:52:45 AM | Info | Copying copy files with delete using script: /var/root/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 09:52:45 AM | Info | Loading 21 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system temporary files.dset
| 09:52:45 AM | Info | Loading 6 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system cache files.dset
| 09:52:45 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Norton FileSaver files.dset
| 09:52:45 AM | Info | Loading 2 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Spotlight search index.dset
| 09:52:45 AM | Info | Loading 0 commands from copy script /var/root/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 09:52:45 AM | Info | /
| 09:52:48 AM | Info | /bin
| 09:52:48 AM | Info | /$RECYCLE.BIN
| 09:52:48 AM | Info | /usr
| 09:53:18 AM | Info | /.scribus
| 09:53:18 AM | Info | /.Spotlight-V100
| 09:53:18 AM | Info | Ignoring /.Spotlight-V100/.journalHistoryLog
| 09:53:18 AM | Info | Ignoring /.Spotlight-V100/.store.db
| 09:53:18 AM | Info | Ignoring /.Spotlight-V100/_exclusions.plist
| 09:53:18 AM | Info | Ignoring /.Spotlight-V100/_rules.plist
| 09:53:18 AM | Info | Ignoring /.Spotlight-V100/ContentIndex.db
| 09:53:18 AM | Info | Ignoring /.Spotlight-V100/store.db
| 09:53:18 AM | Info | /.Trashes
| 09:53:18 AM | Info | /.vol
| 09:53:18 AM | Info | Ignoring /.vol
| 09:53:18 AM | Info | /Applications
| 09:58:19 AM | Info | /automount
| 09:58:19 AM | Info | /Network
| 09:58:19 AM | Info | /Users
| 09:58:49 AM | Info | Did not COPY shared-item /Users/michaelschirmann/Library/Application Support/CrossOver/Bottles/win2000/dosdevices/z: because it would have overwritten the original
| 09:59:16 AM | Info | Did not COPY shared-item /Users/michaelschirmann/.wine/dosdevices/z: because it would have overwritten the original
| 09:59:25 AM | Info | /cores
| 09:59:25 AM | Info | /System
| 10:01:19 AM | Info | Ignoring /System/Library/Extensions.kextcache
| 10:01:19 AM | Info | /sbin
| 10:01:19 AM | Info | /dev
| 10:01:19 AM | Info | /Developer
| 10:01:19 AM | Info | /private
| 10:01:19 AM | Info | Ignoring /private/tmp/501
| 10:01:19 AM | Info | Ignoring /private/tmp/cs_cache_lock_92
| 10:01:19 AM | Info | Ignoring /private/tmp/target.indexState
| 10:01:19 AM | Info | Ignoring /private/var/db/volinfo.database
| 10:01:19 AM | Info | Ignoring /private/var/db/BootCache.playlist
| 10:01:19 AM | Info | WARNING: Caught I/O exception(22): Invalid argument
| 10:01:19 AM | Info | WARNING: Source: /private/var/log/system.log, lstat(): 0
| 10:01:19 AM | Info | WARNING: Target: /Volumes/Macintosh HD 1/private/var/log/system.log, lstat(): 0
| 10:01:19 AM | Info | Attempting to copy file using copyfile().
| 10:01:19 AM | Info | Attempting to copy file using ditto.
| 10:01:19 AM | Error | ditto: /private/var/log/./system.log: Input/output error



The whole thing has been very frustrating and I'm about to give up. This morning I logged into OS X (10.4.11) as the "root" user thinking that might fix the problem, but it didn't.

Any help would be greatly appreciated!

Michael

[dnanian]

Well, this is an I/O error, and it looks to be on the source drive. Did you follow the steps in the Troubleshooting section of the User's Guide?

[mschirma]

I ended up figuring it out, but thank you for the reply.

After running SD a few more times, I managed to determine more specifically the areas that were causing it to fail. I then had SD skip those directories (in the /private/ folder, as I thought), and after it finished doing its backup I went back in and copied the skipped directories by hand. Each one had a handful of files that must have been corrupt, but I elected to delete them. I figured that if they were really corrupt then they must not be used much since I've never had any problems.

SuperDuper is great, I'll definitely recommend it!

Michael

[dnanian]

Glad you're all set, Michael!

[sjk]

Originally Posted by mschirma

Each one had a handful of files that must have been corrupt, but I elected to delete them. I figured that if they were really corrupt then they must not be used much since I've never had any problems.

You might want to check Console output for disk I/O error messages that can be indicators of bad blocks and possible file corruption, e.g.:

Jun 30 20:43:23 lovelight kernel[0]: disk1s2: I/O error.
Jun 30 20:43:53: --- last message repeated 1 time ---
Jun 30 20:44:00 lovelight kernel[0]: disk1s2: I/O error.
Jun 30 20:44:30: --- last message repeated 1 time ---
Jun 30 20:44:37 lovelight kernel[0]: disk1s2: I/O error.
Jun 30 20:45:07: --- last message repeated 1 time ---