error code=3 ACL issue

[vudutu]

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]

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

[vudutu]

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]

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]

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]

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.