ditto - slow time in copy a lot of GB.

Question

ditto - slow time in copy a lot of GB.

My system is an Xserve with 10.4.7 and one XRAID connected to it.
I use a tcsh script to backup my shared folders from the work volume to a backup volume. Both in XRAID and HFS+.

The amount of data to copy is about 300 GB and I have to copy that every night.
To copy all the files and all the resource forks I use ditto -rsrc.

I have experienced that the first night it takes about 3 hours, the night after 4 hours and so on one hour more every night.
But if i restart the server it takes again only 3 hours to do the job!

Talking with Apple Care they told my to format and reinstall the system and confs.
Done, but the problem is still there.

Anyone has experienced the same problem?
Any suggestions is very well come!

Thanx, Gian Luca.

powerMac G5, Mac OS X (10.4.7)

Posted on Aug 31, 2006 8:33 AM

Reply

Answer 1

Aug 31, 2006 4:18 PM in response to Gian Luca Ponti

Welcome to discussions!

Normally, a reboot fixing the problem suggests a memory leak depleting resources. The day after this script runs, check to make sure that it exited properly and that ditto isn't still running. Could you post the script so we can check it out?

If you're doing a full backup, you may want to consider trying asr instead of ditto.

Roger

Reply

Answer 2

Sep 1, 2006 6:47 AM in response to Community User

Thank you Roger!
I think you are right saying there is a memory leak depleting resources...
But checking process in the morning there is no ditto still working.

I never thought to use asr but it could work better!
I will do some test to verify if it can be good for me and if doesn't leak memory.

You can find my script at the end of the post.

Some Info:
- XRAID_01: Source unit
- ServerG5_D2: Destination unit
- found_BkUpDay02: is a file that I use to verify if the Destination volume is mounted

Thanks again for the interest and the welcome.
Gian Luca

#!/bin/tcsh

# ################
# SET VARIABLES
# ################
set BkUpUnit = ServerG5_D2
set f = found_BkUpDay02

# ################
# START SCRIPT
# ################

cd /Volumes
foreach d (*)
if (-e $d/$f) then
# disk found -> set flag to false
set nodisk = 0

echo START $BkUpUnit > /Volumes/XRAID_01/Utenti/gianluca/Desktop/BkUpDay.txt
date >> /Volumes/XRAID_01/Utenti/gianluca/Desktop/BkUpDay.txt

rm -rdf /Volumes/$BkUpUnit/XRAID_01
ditto -rsrc /Volumes/XRAID_01 /Volumes/$BkUpUnit/XRAID_01

echo END $BkUpUnit >> /Volumes/XRAID_01/Utenti/gianluca/Desktop/BkUpDay.txt
date >> /Volumes/XRAID_01/Utenti/gianluca/Desktop/BkUpDay.txt

endif
end

# disk not found

if ( $nodisk == 1 ) then
echo DISK $BkUpUnit NOT FOUND > /Volumes/XRAID_01/Utenti/gianluca/Desktop/DiskBkUpError.txt
endif

exit

powerMac G5 Mac OS X (10.4.7)

Reply

Answer 3

Sep 1, 2006 4:29 PM in response to Gian Luca Ponti

I don't see anything wrong with your script. Below is the script that I use to clone my root drive. I run it a total of four times a day as an at job. If I put a PATH assignment in there, it could be used as a cron job. NOTE: I use case-sensitive journalled HFS+ file systems, so I have to handle things a little differently. So far, I've used this script to do ~900 clones of my root drive. I also run this during business hours with the machine doing it's thing.

#!/bin/bash

MOUNT="/Volumes/$1"

if [ -n "$1" ] && [ -d "$MOUNT" ]
then
START=`date`
exec >> "$0.out"

echo -e "STARTING at: $START\n\n"

diskutil eraseVolume "Case-sensitive Journaled HFS+" $1 "$MOUNT"

asr -verbose -source / -target "$MOUNT"

bless -folder "$MOUNT/System/Library/CoreServices" -bootinfo "$MOUNT/usr/standalone/ppc/bootx.bootinfo" -label $1 -save9

echo -e "\n\nSTARTED : $START"
echo -e "FINISHED: `date`"
echo -e "\n\n"

else
echo -e "\n\tusage: $0 XXXXXXXX\n"
echo -e "Don't forget to quote or escape if there's spaces!\n"
df -h | egrep 'disk|Mount'
echo ""
fi

exit 0

Roger

Reply

Answer 4

Sep 6, 2006 11:57 PM in response to Community User

I have done some tests with the asr command, but unfortunately with no good results.
It takes one hour more to copy all the data every day... like before!
However, thanks for all!

Reply

Answer 5

David_x

Level 4

3,011 points

Sep 7, 2006 5:09 AM in response to Gian Luca Ponti

gianluca, have you looked at rsync with the --archive & --delete options ( & "E") - only changed files would be copied?

-david

Reply

Answer 6

Sep 7, 2006 5:05 PM in response to Gian Luca Ponti

Just as a test, could you put the following 2 commands into your script just before the rm -rdf line:

echo "BEFORE:" > ~/Desktop/roger.txt
top -l 1 -n 10 >> ~/Desktop/roger.txt

and these two after the ditto command:

echo -e "\n\nAFTER:" >> ~/Desktop/roger.txt
top -l 1 -n 10 >> ~/Desktop/roger.txt

and then post roger.txt?

It would be interesting to see the differences in memory usage, and the paging activity of the after. You can run that top command in your shell, and see that it's just a reporting command.

Roger

Reply

Answer 7

MacLemon

Level 2

455 points

Sep 9, 2006 2:51 PM in response to Community User

gianluca.ponti,
since you're running Tiger, is there any particular reason you're not using rsync? The 10.4 version can copy resource forks and do very nice delta backups as well as using hard-links on the backup volume which saves space. I am using a self-written backup script based on rsync which is still rough around the edges, but does backups of several hundred GB FileServers quite successfully.

I know this may not be of help a lot, but I'm interested in the reasons to use ditto over rsync.
MacLemon

Reply

Answer 8

Sep 13, 2006 1:28 AM in response to Community User

I am having some test recently.
Now i am posting the log of the memory usage before and after the backup procedure. In this test I had the backup with asr.

I am also doing some tests with rsynk, but at the beginning I had some problems with extended-attributes (resourceFork).
Solved with rsync version 2.6.6 protocol version 29.

In a few days I will know if it solve my problem or not!
thanks to all!

----- LOG ----
BEFORE:
Processes: 57 total, 2 running, 55 sleeping... 209 threads 00:29:56
Load Avg: 0.01, 0.03, 0.07 CPU usage: 0.0% user, 50.0% sys, 50.0% idle
SharedLibs: num = 164, resident = 26.3M code, 2.26M data, 5.03M LinkEdit
MemRegions: num = 9357, resident = 173M + 6.64M private, 28.1M shared
PhysMem: 227M wired, 111M active, 1.18G inactive, 1.51G used, 1.49G free
VM: 3.82G + 101M 33184(0) pageins, 804(0) pageouts
PID COMMAND %CPU TIME #TH #PRTS #MREGS RPRVT RSHRD RSIZE VSIZE
18491 top 0.0% 0:00.06 1 17 20 184K 364K 592K 26.9M
18487 tcsh 0.0% 0:00.01 1 14 18 236K 616K 700K 31.1M
18486 smbd 0.0% 0:00.01 1 13 49 332K 5.35M 1.60M 32.7M
18479 smbd 0.0% 0:00.01 1 13 49 332K 5.35M 1.69M 32.7M
17966 pickup 0.0% 0:00.03 1 16 19 200K 412K 744K 26.7M
11525 SecurityAg 0.0% 1:05.05 1 71 104 1.65M 7.75M 8.52M 151M
11523 authorizat 0.0% 0:00.03 1 22 24 260K 748K 1.05M 27.3M
11522 mcxd 0.0% 0:02.07 1 42 36 532K 1.18M 2.23M 101M
11518 WindowServ 0.0% 0:10.64 3 85 54 492K 4.72M 4.90M 124M
11516 loginwindo 0.0% 0:00.23 3 110 92 956K 1.55M 3.18M 136M
AFTER:
Processes: 55 total, 2 running, 53 sleeping... 208 threads 04:25:29
Load Avg: 0.40, 0.40, 0.40 CPU usage: 23.1% user, 23.1% sys, 53.8% idle
SharedLibs: num = 164, resident = 26.6M code, 2.55M data, 5.13M LinkEdit
MemRegions: num = 10468, resident = 184M + 6.57M private, 26.0M shared
PhysMem: 273M wired, 110M active, 98.9M inactive, 483M used, 2.53G free
VM: 3.77G + 101M 36028(0) pageins, 804(0) pageouts
PID COMMAND %CPU TIME #TH #PRTS #MREGS RPRVT RSHRD RSIZE VSIZE
19912 top 0.0% 0:00.07 1 17 20 184K 364K 592K 26.9M
19814 pickup 0.0% 0:00.09 1 16 19 180K 420K 724K 26.7M
18487 tcsh 0.0% 0:00.02 1 14 18 236K 616K 696K 31.1M
11525 SecurityAg 0.0% 1:23.28 1 71 104 1.65M 7.75M 8.52M 151M
11523 authorizat 0.0% 0:00.04 1 22 24 260K 748K 1.05M 27.3M
11522 mcxd 0.0% 0:02.60 1 42 36 532K 1.18M 2.23M 101M
11518 WindowServ 0.0% 0:13.52 3 85 54 492K 4.72M 4.90M 124M
11516 loginwindo 0.0% 0:00.24 3 110 92 956K 1.55M 3.18M 136M
7462 qmgr 0.0% 0:00.18 1 16 19 204K 444K 748K 26.8M
6745 check_afp 0.0% 0:08.42 2 24 21 176K 612K 736K 27.1M

Reply

Answer 9

Sep 16, 2006 5:12 PM in response to Gian Luca Ponti

Sorry for not getting back to you sooner. I had a customer that wanted a new website, with a couple of rounds of changes.

The one thing that I noticed comparing the before and after is that in the PhysMem, the wired size went up 46MB. AFAIK, the wired memory is memory that the kernel has gotten that it doesn't release. It could be interesting to watch the wired memory for a few days. Other than that, it looks like what it is, a computer with a LOT of memory doing a sizeable job for 4 hours.

Roger

Reply

Answer 10

Sep 20, 2006 12:39 AM in response to Community User

Continuing tests...
in the last days asr stops to increase the backup time! what a mystery.
Last weekend i tried with rsync but it crashed during backup. I will have more tests with it next days.

Meanwhile i am logging the memory usage before and after the operation.
I put an extract of it below (if it could be useful).

-- PhysMem --

Day 1
Before: 227M wired, 111M active, 1.18G inactive, 1.51G used, 1.49G free
After: 273M wired, 110M active, 98.9M inactive, 483M used, 2.53G free

Day 2
Before: 267M wired, 115M active, 2.58G inactive, 2.96G used, 44.1M free
After: 293M wired, 116M active, 35.4M inactive, 445M used, 2.56G free

Day 3
Before: 350M wired, 120M active, 165M inactive, 636M used, 2.38G free
After: 371M wired, 125M active, 77.1M inactive, 573M used, 2.44G free

Day 4
Before: 341M wired, 144M active, 2.49G inactive, 2.96G used, 38.1M free
After: 366M wired, 142M active, 3.09M inactive, 511M used, 2.50G free

Day 5
Before: 360M wired, 146M active, 2.47G inactive, 2.96G used, 40.8M free
After: 381M wired, 144M active, 3.13M inactive, 529M used, 2.48G free

Reply

Answer 11

MacLemon

Level 2

455 points

Sep 20, 2006 3:29 AM in response to Gian Luca Ponti

As I am very interested in anything rsync, since I do my own backups and customer's backup with rsync I am also interested in your rsync crashes. Can you provide details when or why rsync crashed?

Out of the blue:
Are your files and filesystems sane? Maybe the problem is not the backup software or technique but a problem with the underlying structure on your disks?
MacLemon

Reply

Answer 12

Sep 20, 2006 4:20 PM in response to Gian Luca Ponti

That wired memory is interesting! The way that it increases, it mimics your symptoms real well. I think that it would be reasonable to conclude that some data structure that's common to ditto and asr is handled pretty inefficiently.

Have any of the kernel parameters been changed? Is there anything in /etc/*sysctl.conf ?

I think the fix for this is probably going to get really gnarly into kernel programming, beyond my knowledge. I think that rsync is probably going to be your best bet, plus where it only move updated files, it should run like lightening for you.

Roger

Reply

Answer 13

davidh

Level 4

1,896 points

Sep 21, 2006 4:08 AM in response to Community User

ditto is slow, and from all I understand, if not "depracated" in 10.4, problematic.

By the way, "-rsrc" is the default for ditto as of 10.4

rysnc is rather tricky. If you are not using ACLs, then the Apple-provided rsync should work for you, as of 10.4.6. You'll need matching versions at both ends if you sync across machines.

Please do NOT use RsyncX, the version of rsync it uses is now dated.

If you are at an earlier version of 10.4 and must stay there for now,
I recommend using this version, it's one I've used successfully:
http://www.lartmaker.nl/rsync/

although another "fix" has been posted here:
http://www.onthenet.com.au/~q/rsync/

I have not tried it as the author's not seen fit to explain what he's done and why.

@ Roger: why not use the --erase option with asr ?
"--erase erase erases target and is required if a fast
block-copy restore is desired. By default asr
will do a restore-in-place."

Reply

Answer 14

Sep 22, 2006 1:32 AM in response to davidh

Tonight i've tryed again with rsync (version 2.6.6 protocol version 29), downloaded from http://www.onthenet.com.au/~q/rsync/ .
This is the only version working for me after some tests.

For a clean start i decide to erase all data in destination disk before.
Unfortunately it crash again, but this time i tried to log any actyvity to understand why.

I didn't find anything special to understand what happened.

Follow a short report with some information taken from my logs, so if some one has got any idea is very welcome!!

I have not so great experience in low level system like kernel failure or disk structure problems!
Thanks to all of you guys!

Gian Luca

--- REPORT ---

# rsynk command
/usr/bin/rsync -aExP --delete --exclude='.Spotlight-*' $SourceDisk/ $DestDisk/ > /Volumes/XRAID_02/rsyncOut.log

# from rsyncOut.log
1439283 files to consider

# amount of data copied
55 GB of 297 GB

# from rsync.crash.log
Host Name: xserver
Date/Time: 2006-09-22 03:23:07.514 +0200
OS Version: 10.4.7 (Build 8J135)
Report Version: 4
Command: rsync
Path: /usr/bin/rsync
Parent: rsync [11397]
Version: ??? (???)
PID: 11892
Thread: 0
Exception: EXCBADACCESS (0x0001)
Codes: KERNPROTECTIONFAILURE (0x0002) at 0x00000000
Thread 0 Crashed:
0 libSystem.B.dylib 0x900fc298 aclfromtext + 736
1 rsync 0x0002c864 copyfile_unpack + 604 (copyfile.c:1038)
2 rsync 0x0002b610 copyfile + 468 (copyfile.c:146)
3 rsync 0x0001285c do_copyfile + 104 (syscall.c:273)
4 rsync 0x00002658 finish_transfer + 284 (rsync.c:200)
5 rsync 0x00007f48 recv_files + 3032 (receiver.c:684)
6 rsync 0x0000f6b4 do_recv + 316 (main.c:582)
7 rsync 0x0000fa50 doserverrecv + 564 (main.c:707)
8 rsync 0x0000fb7c start_server + 212 (main.c:739)
9 rsync 0x0000fa94 child_main + 32 (main.c:715)
10 rsync 0x00024e04 local_child + 424 (pipe.c:147)
11 rsync 0x0000ee78 do_cmd + 1120 (main.c:377)
12 rsync 0x0001044c start_client + 1108 (main.c:976)
13 rsync 0x0001098c main + 912 (main.c:1184)
14 rsync 0x00001cbc _start + 760
15 rsync 0x000019c0 start + 48
Thread 0 crashed with PPC Thread State 64:
srr0: 0x00000000900fc298 srr1: 0x100000000000f030 vrsave: 0x0000000000000000
cr: 0x28004422 xer: 0x0000000000000000 lr: 0x00000000900fc280 ctr: 0x00000000901008e0
r0: 0x00000000900fc280 r1: 0x00000000bfffd100 r2: 0x0000000000000000 r3: 0x0000000000000000
r4: 0x00000000901a10ec r5: 0x00000000bfffd144 r6: 0x0000000000000000 r7: 0x0000000000000000
r8: 0x0000000000000003 r9: 0x0000000001804c00 r10: 0x0000000001804c10 r11: 0x0000000000000000
r12: 0x00000000901008e0 r13: 0x00000000a0001910 r14: 0x000000009019bfc0 r15: 0x000000009019bfc0
r16: 0x00000000bfffd140 r17: 0x000000009019bfc0 r18: 0x00000000901a10ec r19: 0xffffffffffffffff
r20: 0x00000000bfffd144 r21: 0x000000009019bfc0 r22: 0x000000000020d000 r23: 0x0000000000303ea0
r24: 0x00000000bfffd13c r25: 0x000000009019bfc0 r26: 0x0000000000303f80 r27: 0x00000000bfffd144
r28: 0x0000000000000001 r29: 0x0000000000303f88 r30: 0x0000000000303f86 r31: 0x00000000900fbfc0
Binary Images Description:
0x1000 - 0x47fff rsync /usr/bin/rsync
0x8fe00000 - 0x8fe52fff dyld 45.3 /usr/lib/dyld
0x90000000 - 0x901bbfff libSystem.B.dylib /usr/lib/libSystem.B.dylib
0x90213000 - 0x90218fff libmathCommon.A.dylib /usr/lib/system/libmathCommon.A.dylib
0x94eec000 - 0x94f09fff libresolv.9.dylib /usr/lib/libresolv.9.dylib

# from top
BEFORE:
Processes: 54 total, 2 running, 52 sleeping... 209 threads 00:29:56
Load Avg: 0.06, 0.07, 0.19 CPU usage: 0.0% user, 66.7% sys, 33.3% idle
SharedLibs: num = 172, resident = 33.5M code, 2.95M data, 6.16M LinkEdit
MemRegions: num = 9313, resident = 107M + 6.59M private, 41.3M shared
PhysMem: 391M wired, 149M active, 2.44G inactive, 2.97G used, 33.7M free
VM: 3.84G + 103M 111346(0) pageins, 2482(0) pageouts
AFTER:
Processes: 56 total, 4 running, 1 stuck, 51 sleeping... 212 threads 03:23:13
Load Avg: 0.85, 0.88, 0.92 CPU usage: 7.1% user, 92.9% sys, 0.0% idle
SharedLibs: num = 172, resident = 33.5M code, 3.36M data, 6.17M LinkEdit
MemRegions: num = 10660, resident = 121M + 7.16M private, 45.6M shared
PhysMem: 403M wired, 149M active, 1.59G inactive, 2.13G used, 890M free
VM: 3.98G + 103M 113453(0) pageins, 3223(0) pageouts

Reply

Answer 15

davidh

Level 4

1,896 points

Sep 22, 2006 4:10 AM in response to Gian Luca Ponti

Two things,

that version of rsync, as the page says, should be in
/usr/local/rysnc

and so you need to invoke it directly. You used the Apple-provided version which is located at /usr/bin/rsync

Change your command to:
/usr/local/bin/rsync -aExP (etc.)

In seeing
0 libSystem.B.dylib 0x900fc298 acl fromtext + 736

in the log outpput, I'm wondering: as asked, are you using ACLs ?
If so, the issue is specifically that the Apple-provided rsync crashes when ACLs are in use.

So then, try again but use:
/usr/local/bin/rsync

or wherever you installed it.

Reply