This is perhaps the deleted file processing pass that happens at the end of a standard incremental backup. The server sends a list of all the files it thinks it has back to the client so the client can compare them to what it knows it has and then ask the server to mark the deleted files inactive. I've not seen this happen with the relatively small number of files you show here but this is probably it. To prove it, try an incremental/fast on this server and see if the delay between file spaces is eliminated. The /fast tells the client to not do the deleted file pass.
Kelly Lipp CTO STORServer, Inc. 485-B Elkton Drive Colorado Springs, CO 80907 719-266-8777 www.storserver.com -----Original Message----- From: ADSM: Dist Stor Manager [mailto:[EMAIL PROTECTED] On Behalf Of Michael Green Sent: Tuesday, April 08, 2008 12:59 AM To: [email protected] Subject: [ADSM-L] Long delay between FileSpaces backups I have noticed that several nodes exhibit long delays between when backup of one filespace ends and the next one starts. Here is an excerpt from one dsmsched.log file that illustrates the problem: 04/07/2008 21:00:12 --- SCHEDULEREC OBJECT BEGIN F2UX_INC_BKP1 04/07/2008 21:00:00 04/07/2008 21:00:12 Incremental backup of volume '/' 04/07/2008 21:00:12 Incremental backup of volume '/boot' 04/07/2008 21:00:12 Incremental backup of volume '/home' 04/07/2008 21:00:14 Successful incremental backup of '/boot' 04/07/2008 21:19:29 ANS1898I ***** Processed 3,000 files ***** 04/07/2008 21:19:30 ANS1898I ***** Processed 22,000 files ***** 04/07/2008 21:19:31 ANS1898I ***** Processed 40,000 files ***** 04/07/2008 21:19:32 ANS1898I ***** Processed 56,500 files ***** 04/07/2008 21:19:33 ANS1898I ***** Processed 73,000 files ***** 04/07/2008 21:19:34 ANS1898I ***** Processed 89,000 files ***** 04/07/2008 21:19:35 ANS1898I ***** Processed 107,000 files ***** 04/07/2008 21:19:36 ANS1898I ***** Processed 125,500 files ***** 04/07/2008 21:19:37 ANS1898I ***** Processed 143,500 files ***** 04/07/2008 21:19:38 ANS1898I ***** Processed 161,500 files ***** 04/07/2008 21:19:39 ANS1898I ***** Processed 176,500 files ***** 04/07/2008 21:19:40 ANS1898I ***** Processed 180,000 files ***** 04/07/2008 21:19:40 Normal File--> 445 /opt/tivoli/tsm/client/ba/bin/tsmstats.ini [Sent] 04/07/2008 21:19:40 Normal File--> 834,182 /var/cache/man/whatis [Sent] 04/07/2008 21:19:40 Normal File--> 1,282 /var/lib/logrotate.status [Sent] 04/07/2008 21:19:47 Normal File--> 87,070,388 /var/lib/mlocate/mlocate.db [Sent] 04/07/2008 21:19:47 Normal File--> 72 /var/lib/nfs/rmtab [Sent] 04/07/2008 21:19:47 Normal File--> 6 /var/lib/ntp/drift [Sent] 04/07/2008 21:19:47 Normal File--> 23,040 /var/log/btmp [Sent] 04/07/2008 21:19:47 Normal File--> 3,497 /var/log/cron [Sent] 04/07/2008 21:19:47 Normal File--> 332 /var/log/dsmerror.log [Sent] 04/07/2008 21:19:47 Normal File--> 11,126,980 /var/log/dsmsched.log Changed 04/07/2008 21:19:47 Retry # 1 Normal File--> 72 /var/lib/nfs/rmtab [Sent] 04/07/2008 21:19:47 Retry # 1 Normal File--> 6 /var/lib/ntp/drift [Sent] 04/07/2008 21:19:47 Retry # 1 Normal File--> 23,040 /var/log/btmp [Sent] 04/07/2008 21:19:47 Retry # 1 Normal File--> 3,497 /var/log/cron [Sent] 04/07/2008 21:19:47 Retry # 1 Normal File--> 332 /var/log/dsmerror.log [Sent] 04/07/2008 21:19:48 Retry # 1 Normal File--> 11,128,049 /var/log/dsmsched.log Changed 04/07/2008 21:19:49 Retry # 2 Normal File--> 11,128,144 /var/log/dsmsched.log Changed 04/07/2008 21:19:49 Retry # 3 Normal File--> 11,128,144 /var/log/dsmsched.log [Sent] 04/07/2008 21:19:49 Normal File--> 41,712 /var/log/dsmwebcl.log [Sent] 04/07/2008 21:19:49 Normal File--> 5,250,452 /var/log/lastlog [Sent] 04/07/2008 21:19:49 Normal File--> 881 /var/log/maillog [Sent] 04/07/2008 21:19:49 Normal File--> 955 /var/log/messages [Sent] 04/07/2008 21:19:49 Normal File--> 44,100 /var/log/rpmpkgs [Sent] 04/07/2008 21:19:49 Normal File--> 2,354 /var/log/secure [Sent] 04/07/2008 21:19:49 Normal File--> 12,672 /var/log/wtmp [Sent] 04/07/2008 21:19:49 Normal File--> 4,419,337 /var/log/audit/audit.log [Sent] 04/07/2008 21:19:49 Normal File--> 1,448 /var/log/mail/statistics [Sent] 04/07/2008 21:19:49 Normal File--> 13,056 /var/run/utmp [Sent] 04/07/2008 21:19:49 Normal File--> 9 /var/spool/anacron/cron.daily [Sent] 04/07/2008 21:19:50 Normal File--> 599,856 /var/spool/mail/root [Sent] 04/07/2008 21:20:07 Successful incremental backup of '/' 04/08/2008 04:39:08 ANS1898I ***** Processed 180,500 files ***** 04/08/2008 04:39:10 ANS1898I ***** Processed 181,000 files ***** Note the time difference between when backup of '/' end and next filespace starts! Is this a known bug or a performance problem I'm having here? If this is a performance problem, what are the initial steps should be taken to address the issue? Server: 5.3.6/Linux86 (SLES9) Client: 5.4.1.5/Linux86 (RedHat EL 5.0) -- Warm regards, Michael Green
