Shirt Pocket Discussions

Shirt Pocket Discussions (http://www.shirt-pocket.com/forums/index.php)
-   General (http://www.shirt-pocket.com/forums/forumdisplay.php?f=6)
-   -   error code=3 ACL issue (http://www.shirt-pocket.com/forums/showthread.php?t=1875)

vudutu 12-09-2006 07:56 PM

error code=3 ACL issue
 
This was the first attempt at a BU on my OSX Xserver running 10.4.7. On my BU drive I have three partitions the OS BU is 125 gig, the Faculty BU partition is 125 Gig, the Students BU partition is 215 gig. This is on a LaCie Big disk, 500 gig. The problem is with the Students BU. the error code is =3 See logs below.

The Vol info on that partition says Capacity 215.23 gig, Avail 117.08 gig, Used 98.15. The folder I was backing up says its size on the BU is 3.78 Gig.

I have read the threads on the ACL issues and set Copy ACLs in Advanced but do not understand the issue and what to do. Should I attempt to repair permissions on this vol or run Disk Warrior? How serious is the problem?



| 04:11:22 AM | Info | SuperDuper!, 2.1.3 (80), path: /Applications/SuperDuper!.app, Mac OS 10.4.7 build 8J135 (ppc)
| 04:11:22 AM | Info | Started on Fri, Dec 8, 2006 at 4:11 AM
| 04:11:22 AM | Info | Source Drive: Students, mount: /Volumes/Students, device: Hitachi HDS722525VLSA80, interconnect: Internal ATA, file system: "Journaled HFS+", OS: N/A, capacity: 233.64 GB, used: 131.97 GB, directories: 75259, files: 223141, ejectable: NO, ACLs: Enabled
| 04:11:22 AM | Info | Target Drive: Student BU, mount: /Volumes/Student BU, device: LaCie Big Disk G465, interconnect: External FireWire, file system: "Journaled HFS+", OS: N/A, capacity: 215.23 GB, used: 0.07 GB, directories: 3, files: 2, ejectable: NO, ACLs: Disabled
| 04:11:22 AM | Info | Copy Mode : Erase, then copy files
| 04:11:22 AM | Info | Copy Script : Backup - all files.dset
| 04:11:22 AM | Info | Transcript : BuildTranscript.plist
| 04:11:22 AM | Info | PHASE: 1. Prepare to Copy Files
| 04:11:22 AM | Info | ...ACTION: Preparing Students
| 04:11:22 AM | Info | ......COMMAND => Verifying the integrity of volinfo.database
| 04:11:22 AM | Info | volinfo.database OK
| 04:11:22 AM | Info | ......COMMAND => Enabling permissions on Students
| 04:11:22 AM | Info | Refreshing Disk Arbitration ...
| 04:11:23 AM | Info | ......COMMAND => Verifying that permissions are enabled for Students
| 04:11:23 AM | Info | Permissions on '/Volumes/Students' are enabled.
| 04:11:23 AM | Info | ...ACTION: Erasing Student BU
| 04:11:23 AM | Info | ......COMMAND => Preserving Student BU UUID
| 04:11:24 AM | Info | CA75EF347F96A389
| 04:11:24 AM | Info | ......COMMAND => Preserving spotlight indexing state
| 04:11:24 AM | Info | ......COMMAND => Erasing Student BU
| 04:11:35 AM | Info | ......COMMAND => Restoring Student BU UUID (CA75EF347F96A389)
| 04:11:37 AM | Info | CA75EF347F96A389
| 04:11:37 AM | Info | ......COMMAND => Restoring Spotlight search indexing state on Student BU
| 04:11:37 AM | Info | ...ACTION: Preparing Student BU
| 04:11:37 AM | Info | ......COMMAND => Enabling permissions on Student BU
| 04:11:37 AM | Info | Refreshing Disk Arbitration ...
| 04:11:37 AM | Info | ......COMMAND => Verifying that permissions are enabled for Student BU
| 04:11:37 AM | Info | Permissions on '/Volumes/Student BU' are enabled.
| 04:11:37 AM | Info | ......COMMAND => Verifying that Student BU ACL support matches Students
| 04:11:37 AM | Info | ...ACTION: Preserving Spotlight state on Student BU
| 04:11:37 AM | Info | ......COMMAND => Disabling Spotlight search indexing on Student BU
| 04:11:37 AM | Info | PHASE: 2. Copy Files
| 04:11:37 AM | Info | ...ACTION: Copying files from Students to Student BU
| 04:11:37 AM | Info | ......COMMAND => Cloning Students to Student BU
| 04:11:39 AM | Info | Copying copy files using script: /Users/adminx/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 04:11:39 AM | Info | Loading 19 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system temporary files.dset
| 04:11:39 AM | Info | Loading 6 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system cache files.dset
| 04:11:39 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Norton FileSaver files.dset
| 04:11:39 AM | Info | Loading 2 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Spotlight search index.dset
| 04:11:39 AM | Info | Loading 0 commands from copy script /Users/adminx/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 04:11:39 AM | Info | /Volumes/Students
| 04:11:42 AM | Info | /Volumes/Students/StudentHomes
| 05:55:23 AM | Error | SDCopy(9111) malloc: *** vm_allocate(size=8421376) failed (error code=3)


**************

04:05:58 AM | Info | SuperDuper!, 2.1.3 (80), path: /Applications/SuperDuper!.app, Mac OS 10.4.7 build 8J135 (ppc)
| 04:05:58 AM | Info | Started on Sat, Dec 9, 2006 at 4:05 AM
| 04:05:58 AM | Info | Source Drive: Students, mount: /Volumes/Students, device: Hitachi HDS722525VLSA80, interconnect: Internal ATA, file system: "Journaled HFS+", OS: N/A, capacity: 233.64 GB, used: 137.67 GB, directories: 75073, files: 224570, ejectable: NO, ACLs: Enabled
| 04:05:58 AM | Info | Target Drive: Student BU, mount: /Volumes/Student BU, device: LaCie Big Disk G465, interconnect: External FireWire, file system: "Journaled HFS+", OS: N/A, capacity: 215.23 GB, used: 133.70 GB, directories: 75009, files: 222648, ejectable: NO, ACLs: Enabled
| 04:05:58 AM | Info | Copy Mode : Erase, then copy files
| 04:05:58 AM | Info | Copy Script : Backup - all files.dset
| 04:05:58 AM | Info | Transcript : BuildTranscript.plist
| 04:05:59 AM | Info | PHASE: 1. Prepare to Copy Files
| 04:05:59 AM | Info | ...ACTION: Preparing Students
| 04:05:59 AM | Info | ......COMMAND => Verifying the integrity of volinfo.database
| 04:05:59 AM | Info | volinfo.database OK
| 04:05:59 AM | Info | ......COMMAND => Enabling permissions on Students
| 04:05:59 AM | Info | Refreshing Disk Arbitration ...
| 04:05:59 AM | Info | ......COMMAND => Verifying that permissions are enabled for Students
| 04:06:00 AM | Info | Permissions on '/Volumes/Students' are enabled.
| 04:06:00 AM | Info | ...ACTION: Erasing Student BU
| 04:06:00 AM | Info | ......COMMAND => Preserving Student BU UUID
| 04:06:01 AM | Info | CA75EF347F96A389
| 04:06:01 AM | Info | ......COMMAND => Preserving spotlight indexing state
| 04:06:01 AM | Info | ......COMMAND => Erasing Student BU
| 04:06:11 AM | Info | ......COMMAND => Restoring Student BU UUID (CA75EF347F96A389)
| 04:06:12 AM | Info | CA75EF347F96A389
| 04:06:12 AM | Info | ......COMMAND => Restoring Spotlight search indexing state on Student BU
| 04:06:12 AM | Info | ...ACTION: Preparing Student BU
| 04:06:12 AM | Info | ......COMMAND => Enabling permissions on Student BU
| 04:06:12 AM | Info | Refreshing Disk Arbitration ...
| 04:06:12 AM | Info | ......COMMAND => Verifying that permissions are enabled for Student BU
| 04:06:12 AM | Info | Permissions on '/Volumes/Student BU' are enabled.
| 04:06:12 AM | Info | ......COMMAND => Verifying that Student BU ACL support matches Students
| 04:06:12 AM | Info | ...ACTION: Preserving Spotlight state on Student BU
| 04:06:12 AM | Info | ......COMMAND => Disabling Spotlight search indexing on Student BU
| 04:06:13 AM | Info | PHASE: 2. Copy Files
| 04:06:13 AM | Info | ...ACTION: Copying files from Students to Student BU
| 04:06:13 AM | Info | ......COMMAND => Cloning Students to Student BU
| 04:06:13 AM | Info | Copying copy files using script: /Users/adminx/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 04:06:13 AM | Info | Loading 19 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system temporary files.dset
| 04:06:13 AM | Info | Loading 6 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system cache files.dset
| 04:06:13 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Norton FileSaver files.dset
| 04:06:13 AM | Info | Loading 2 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Spotlight search index.dset
| 04:06:13 AM | Info | Loading 0 commands from copy script /Users/adminx/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 04:06:14 AM | Info | /Volumes/Students
| 04:06:16 AM | Info | /Volumes/Students/StudentHomes
| 05:50:40 AM | Error | SDCopy(22848) malloc: *** vm_allocate(size=8421376) failed (error code=3)
| 05:50:40 AM | Error | SDCopy(22848) malloc: *** error: can't allocate region
| 05:50:41 AM | Error | SDCopy(22848) malloc: *** set a breakpoint in szone_error to debug
| 05:50:41 AM | Error | SDCopy(22848) malloc: *** vm_allocate(size=8421376) failed (error code=3)
| 05:50:41 AM | Error | SDCopy(22848) malloc: *** error: can't allocate region
| 05:50:41 AM | Error | SDCopy(22848) malloc: *** set a breakpoint in szone_error to debug

dnanian 12-10-2006 01:25 AM

Try turning ACL copy off in the Advanced tab of Options...

vudutu 12-11-2006 11:21 AM

OK will try but can you anwer the rest of my question (see below) explain or point me some where so I can better understand? What happens if I have backed up with ALC off and restore that BU?

"I have read the threads on the ACL issues and set Copy ACLs in Advanced but do not understand the issue and what to do. Should I attempt to repair permissions on this vol or run Disk Warrior? How serious is the problem?"

dnanian 12-11-2006 11:24 AM

It means you need to re-apply the ACLs (which is typically not onerous, because of the way ACLs inherit). Repairing won't always fix the problem, which is in the low-level ACL copying code in OSX itself...

vudutu 12-12-2006 10:24 AM

Turning off did not help, same error. I'll Google and read up on ACLs. Should I attempt to repair permissions on this vol or run Disk Warrior? How serious is the problem, could this be why I am getting odd problems for users such as not allowing them to write to their desktop and apps that won't launch? Any word from Apple on the problem or when is a fix is due? FYI I am running LDAP and their home directories reside on the server. Thanks for your help.

dnanian 12-12-2006 10:26 AM

Definitely run Disk Warrior, then -- if you're not copying ACLs (and you ran it manually, as opposed to scheduled where you changed the main window but didn't recreate the scheduled copy), and you got this error, it's likely you have damage in the attribute b-tree which the latest Disk Warrior will repair.

vudutu 12-12-2006 01:40 PM

I did NOT run manually I let the schedule run it,

not sure what this means (where you changed the main window but didn't recreate the scheduled copy)

I love SuperDuper and suggest it to all my friends and clients, the basic interface is great but this is the first time I have set up a multi vol backup and I find it a little confusing as I was trying to turn off "copy ACL's" in just the the vol BU I was having the error on (Students), in fact I went back yesterday morn, killed all the scheduled sessions because I was a little foggy, or was it that wonderful Ribera del Duero Spanish Tempranillo red I had with dinner, anyway, I set them all three up again with copy ACL's off. Also I notice in the SuperDuper window it says "ACL's will not be copied but not in the schedule window. So it looks like "copy ACL's" is global not able to be set for a particular schedule.

I'll come in this weekend and take the server down and run Diskwarrior. Any word from Apple on the problem or when is a fix is due?
Thanks

dnanian 12-12-2006 02:23 PM

Here's the thing: when you schedule a copy, it's no longer "associated" with the main window. It's totally separate. So, if you change the main window, the already-created schedule is not affected.

If you want to change something about a schedule other than the values that you can modify when you select the scheduled copy and click "Edit", you have to delete the one you have and recreate it.

So -- at this point you have recreated the scheduled copies with ACL copy off?

vudutu 12-13-2006 12:38 PM

Yes, I recreated, it ran last night and WORKED YAHOOO, below is the log, what I dont get is why it ran and the previous (see previous log for student) did not as both show ACLs off. I'll sit down and compair the logs more closely today. thanks for your help. I'll come in this weekend and take the server down run Diskwarrior and Applejack and try again, count me in on testing for the ACL's issue. SuperDuper ROCKS! I don't know what I would do without you guys and Bombich!

| 04:00:13 AM | Info | SuperDuper!, 2.1.3 (80), path: /Applications/SuperDuper!.app, Mac OS 10.4.7 build 8J135 (ppc)
| 04:00:13 AM | Info | Started on Wed, Dec 13, 2006 at 4:00 AM
| 04:00:13 AM | Info | Source Drive: Students, mount: /Volumes/Students, device: Hitachi HDS722525VLSA80, interconnect: Internal ATA, file system: "Journaled HFS+", OS: N/A, capacity: 233.64 GB, used: 139.72 GB, directories: 75366, files: 226189, ejectable: NO, ACLs: Enabled
| 04:00:13 AM | Info | Target Drive: Student BU, mount: /Volumes/Student BU, device: LaCie Big Disk G465, interconnect: External FireWire, file system: "Journaled HFS+", OS: N/A, capacity: 215.23 GB, used: 103.03 GB, directories: 49204, files: 152558, ejectable: NO, ACLs: Enabled
| 04:00:13 AM | Info | Copy Mode : Smart Update
| 04:00:13 AM | Info | Copy Script : Backup - all files.dset
| 04:00:13 AM | Info | Transcript : BuildTranscript.plist
| 04:00:14 AM | Info | PHASE: 1. Prepare to Copy Files
| 04:00:14 AM | Info | ...ACTION: Preparing Students
| 04:00:14 AM | Info | ......COMMAND => Verifying the integrity of volinfo.database
| 04:00:14 AM | Info | volinfo.database OK
| 04:00:14 AM | Info | ......COMMAND => Enabling permissions on Students
| 04:00:14 AM | Info | Refreshing Disk Arbitration ...
| 04:00:14 AM | Info | ......COMMAND => Verifying that permissions are enabled for Students
| 04:00:14 AM | Info | Permissions on '/Volumes/Students' are enabled.
| 04:00:14 AM | Info | ...ACTION: Preparing Student BU
| 04:00:14 AM | Info | ......COMMAND => Enabling permissions on Student BU
| 04:00:15 AM | Info | Refreshing Disk Arbitration ...
| 04:00:15 AM | Info | ......COMMAND => Verifying that permissions are enabled for Student BU
| 04:00:15 AM | Info | Permissions on '/Volumes/Student BU' are enabled.
| 04:00:15 AM | Info | ......COMMAND => Verifying that Student BU ACL support matches Students
| 04:00:15 AM | Info | ...ACTION: Preserving Spotlight state on Student BU
| 04:00:15 AM | Info | ......COMMAND => Disabling Spotlight search indexing on Student BU
| 04:00:15 AM | Info | PHASE: 2. Copy Files
| 04:00:15 AM | Info | ...ACTION: Copying files from Students to Student BU using Smart Update
| 04:00:15 AM | Info | ......COMMAND => Cloning Students to Student BU
| 04:00:16 AM | Info | Copying skip files with delete using script: /Users/adminx/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 04:00:16 AM | Info | ACLs from Students will not be copied to Student BU.
| 04:00:16 AM | Info | Loading 19 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system temporary files.dset
| 04:00:16 AM | Info | Loading 6 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude system cache files.dset
| 04:00:16 AM | Info | Loading 1 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Norton FileSaver files.dset
| 04:00:16 AM | Info | Loading 2 commands from copy script /Applications/SuperDuper!.app/Contents/Resources/Copy Scripts/Exclude Spotlight search index.dset
| 04:00:16 AM | Info | Loading 0 commands from copy script /Users/adminx/Library/Application Support/SuperDuper!/Copy Scripts/Standard Scripts/Backup - all files.dset
| 04:00:16 AM | Info | /Volumes/Students
| 04:00:19 AM | Info | /Volumes/Students/StudentHomes
| 04:49:19 AM | Info | /Volumes/Students/.Trashes
| 04:49:19 AM | Info | Ignoring /Volumes/Students/.Trashes/501/rtalty
| 04:49:19 AM | Info | Ignoring /Volumes/Students/Desktop DB
| 04:49:19 AM | Info | Ignoring /Volumes/Students/Desktop DF
| 04:49:19 AM | Info | Evaluated 301554 items occupying 139.40 GB (75366 directories, 222623 files, 3565 symlinks)
| 04:49:19 AM | Info | Copied 132118 items totaling 38.10 GB (26880 directories, 74794 files, 30444 symlinks)
| 04:49:19 AM | Info | Cloned 139.23 GB of data in 2943 seconds at an effective transfer rate of 48.45 MB/s
| 04:49:19 AM | Info | PHASE: 3. After Successful Copy
| 04:49:19 AM | Info | ...ACTION: Restoring Spotlight state on Student BU
| 04:49:19 AM | Info | ......COMMAND => Restoring Spotlight search indexing state on Student BU
| 04:49:19 AM | Info | Copy complete.

dnanian 12-13-2006 03:32 PM

Great: glad that worked!


All times are GMT -4. The time now is 02:23 AM.

Powered by vBulletin® Version 3.8.9
Copyright ©2000 - 2017, vBulletin Solutions, Inc.