returns partial output after parsing the log

[barkath]

Hello,

Looks like I could be missing something simple in here, I have perl script running on my production server that is giving partial output. I run 2 scripts, one will backup the server to TSM and another (check_dsmsched.pl as seen below) will parse the TSM schedule log from /var/log/dsmsched.log and emails the results.

I could see it is generating the log correctly but not emailing the complete results.

===========================================
check_dsmsched.pl
=================================
#!/usr/bin/perl –w

#
# check_dsmsched.pl

# This script will parse the TSM schedule log, and E-mail results.

# It is invoked by the TSM scheduler process, postschedulecmd option.

use Mail::Sender;
chomp ($HOSTNAME=`hostname`);

$DAY=24*60*60; # seconds in a day
%rcpt=(
'MAILSVCS', 'barkath@gmail.com',
);
@sched_out=();

sub check_dsmsched_log # subr uses 1 param (an integer)
{
@t=localtime(time-$DAY*$_[0]); # build localtime array (T-x)
$t[4]++; # month
$t[5]-=100; # year
$t[3]="0$t[3]" if ($t[3] < 10); # pad a zero
$t[4]="0$t[4]" if ($t[4] < 10); # pad z zero
$t[5]="0$t[5]" if ($t[5] < 10); # pad z zero

$date="$t[4]/$t[3]/$t[5]";

$DSMSCHED="/var/log/dsmsched.log";
$DSMPRUNE="/tmp/dsmprune.log";
$index=1;
$sched_out[0]="CUSTOM IDX/CACHE backup PART 1 results:\n\n";
################################ PRUNING PASS 1 ###############################
# Prunes everything not matching the $date string
# open (INFILE,"<$DSMSCHED");
# open (OUTFILE,">$DSMPRUNE");
# while (<INFILE>)
# {
# if (/^$date/)
# {
# print OUTFILE;
# }
# }
# close INFILE;
# close OUTFILE;

################################ PRUNING PASS 2 ###############################
# Prunes everything but the results of CUSTOM_IDX_PART_1
open (INFILE,"<$DSMPRUNE");
while (<INFILE>)
{
next while (! /SCHEDULEREC OBJECT BEGIN CUSTOM_IDX_PART_1/);
while (<INFILE>)
{
last if (/SCHEDULEREC OBJECT END CUSTOM_IDX_PART_1/);
next if (/Normal File/ || /Expiring/ || /Special File/ || /Directory/ || /Symbolic Link/ || /Updating/ || /ANS1898I/ );
$sched_out[$index]=$_; # build the results array
$index++;
}
last;
}
close INFILE;
}

check_dsmsched_log(0); # run on current day (T - 0)
# Run on yesterday (T - 1) if (T - 0) yielded no results.
check_dsmsched_log(1) if (! defined $sched_out[1]);

chomp ($date=`date +"%A, %B %d, %Y, %H:%M:%S"`);
$sender = new Mail::Sender({
smtp => '10.10.10.10',
from => "idx_backup\@$HOSTNAME",
subject => "IDX Backup status $date"
});
$sender->MailMsg({
msg => "@sched_out",
to => "${$rcpt{'MAILSVCS'}}"
});



============================================
/var/log/dsmsched.log file
============================================

10/24/07 08:28:15 --- SCHEDULEREC STATUS BEGIN
10/24/07 08:28:15 Session established with server AIXTSM1: AIX-RS/6000
10/24/07 08:28:15 Server Version 5, Release 2, Level 4.4
10/24/07 08:28:15 Server date/time: 10/24/07 08:28:15 Last access: 10/23/07 21:01:18

10/24/07 08:28:15 Total number of objects inspected: 121,958
10/24/07 08:28:15 Total number of objects backed up: 752
10/24/07 08:28:15 Total number of objects updated: 0
10/24/07 08:28:15 Total number of objects rebound: 0
10/24/07 08:28:15 Total number of objects deleted: 0
10/24/07 08:28:15 Total number of objects expired: 231
10/24/07 08:28:15 Total number of objects failed: 3
10/24/07 08:28:15 Total number of bytes transferred: 485.23 GB
10/24/07 08:28:15 Data transfer time: 23,474.35 sec
10/24/07 08:28:15 Network data transfer rate: 21,674.99 KB/sec
10/24/07 08:28:15 Aggregate data transfer rate: 12,330.80 KB/sec
10/24/07 08:28:15 Objects compressed by: 0%
10/24/07 08:28:15 Elapsed processing time: 11:27:43
10/24/07 08:28:15 --- SCHEDULEREC STATUS END
10/24/07 08:28:15 --- SCHEDULEREC OBJECT END CUSTOM_IDX_PART_1 10/23/07 21:00:00
10/24/07 08:28:15
Executing Operating System command or script:
/usr/local/sbin/check_dsmsched.pl
10/24/07 08:28:16 Finished command. Return code is: 0
10/24/07 08:28:16 Scheduled event 'CUSTOM_IDX_PART_1' completed successfully.
10/24/07 08:28:16 Sending results for scheduled event 'CUSTOM_IDX_PART_1'.
10/24/07 08:28:16 Session established with server AIXTSM1: AIX-RS/6000
10/24/07 08:28:16 Server Version 5, Release 2, Level 4.4
10/24/07 08:28:16 Server date/time: 10/24/07 08:28:16 Last access: 10/24/07 08:28:15

10/24/07 08:28:16 Results sent to server for scheduled event 'CUSTOM_IDX_PART_1'.

10/24/07 08:28:16 ANS1483I Schedule log pruning started.
10/24/07 08:28:17 ANS1484I Schedule log pruning finished successfully.
10/24/07 08:28:17 Querying server for next scheduled event.
10/24/07 08:28:17 Node Name: AIXIDX
10/24/07 08:28:17 Session established with server AIXTSM1: AIX-RS/6000
10/24/07 08:28:17 Server Version 5, Release 2, Level 4.4
10/24/07 08:28:17 Server date/time: 10/24/07 08:28:17 Last access: 10/24/07 08:28:16

10/24/07 08:28:17 --- SCHEDULEREC QUERY BEGIN
10/24/07 08:28:17 --- SCHEDULEREC QUERY END
10/24/07 08:28:17 Next operation scheduled:
10/24/07 08:28:17 ------------------------------------------------------------
10/24/07 08:28:17 Schedule Name: CUSTOM_IDX_PART_1
10/24/07 08:28:17 Action: Incremental
10/24/07 08:28:17 Objects: / /var /home /usr /opt /winshare /transfer /ftp /mjournal /dbu /arc /winshare2 /dbb
10/24/07 08:28:17 Options:
10/24/07 08:28:17 Server Window Start: 21:00:00 on 10/24/07
10/24/07 08:28:17 ------------------------------------------------------------
10/24/07 08:28:17 Waiting to be contacted by the server.
10/24/07 21:00:02 Querying server for next scheduled event.
10/24/07 21:00:02 Node Name: AIXIDX
10/24/07 21:00:02 Session established with server AIXTSM1: AIX-RS/6000
10/24/07 21:00:02 Server Version 5, Release 2, Level 4.4
10/24/07 21:00:02 Server date/time: 10/24/07 21:00:02 Last access: 10/24/07 08:28:17

10/24/07 21:00:02 --- SCHEDULEREC QUERY BEGIN
10/24/07 21:00:02 --- SCHEDULEREC QUERY END
10/24/07 21:00:02 Next operation scheduled:
10/24/07 21:00:02 ------------------------------------------------------------
10/24/07 21:00:02 Schedule Name: CUSTOM_IDX_PART_1
10/24/07 21:00:02 Action: Incremental
10/24/07 21:00:02 Objects: / /var /home /usr /opt /winshare /transfer /ftp /mjournal /dbu /arc /winshare2 /dbb
10/24/07 21:00:02 Options:
10/24/07 21:00:02 Server Window Start: 21:00:00 on 10/24/07
10/24/07 21:00:02 ------------------------------------------------------------
10/24/07 21:00:02
Executing scheduled command now.
10/24/07 21:00:02
Executing Operating System command or script:
/usr/local/sbin/backup_cache.pl
10/24/07 21:00:33 Finished command. Return code is: 0
10/24/07 21:00:33 --- SCHEDULEREC OBJECT BEGIN CUSTOM_IDX_PART_1 10/24/07 21:00:00
10/24/07 21:00:33 Incremental backup of volume '/'
10/24/07 21:00:33 Incremental backup of volume '/var'
10/24/07 21:00:33 Incremental backup of volume '/home'
10/24/07 21:00:33 Incremental backup of volume '/usr'
10/24/07 21:00:33 Incremental backup of volume '/opt'
10/24/07 21:00:33 Incremental backup of volume '/winshare'
10/24/07 21:00:33 Incremental backup of volume '/transfer'
10/24/07 21:00:33 Incremental backup of volume '/ftp'
10/24/07 21:00:33 Incremental backup of volume '/mjournal'
10/24/07 21:00:48 Successful incremental backup of '/var'
10/24/07 21:00:51 ANS1898I ***** Processed 9,000 files *****
10/24/07 21:00:51 Successful incremental backup of '/home'
10/24/07 21:00:51 Successful incremental backup of '/opt'
.
.
.

============================================
Currently am getting Incomplete Results:
=========================
CUSTOM IDX/CACHE backup PART 1 results:

10/29/07 21:00:31 Incremental backup of volume '/'
10/29/07 21:00:31 Incremental backup of volume '/var'
10/29/07 21:00:31 Incremental backup of volume '/home'
10/29/07 21:00:31 Incremental backup of volume '/usr'
10/29/07 21:00:31 Incremental backup of volume '/opt'
10/29/07 21:01:43 Successful incremental backup of '/arc'
.
.
.
10/29/07 21:01:43 Successful incremental backup of '/winshare2'
10/29/07 21:03:07 Successful incremental backup of '/mjournal'
10/29/07 22:35:09 ANS1228E Sending of object '/dbb/ugreg/CACHE.DAT' failed
10/29/07 22:35:09 ANS4037E File '/dbb/ugreg/CACHE.DAT' changed during processing. File skipped.
10/29/07 22:59:02 ANS1228E Sending of object '/dbb/upgrade/CACHE.DAT' failed
10/29/07 22:59:02 ANS4037E File '/dbb/upgrade/CACHE.DAT' changed during processing. File skipped.

=============================================
whereas the correct output should look like below:
====================================
CUSTOM IDX/CACHE backup PART 1 results:

10/05/07 21:00:32 Incremental backup of volume '/'
10/05/07 21:00:32 Incremental backup of volume '/var'
10/05/07 21:00:32 Incremental backup of volume '/home'
10/05/07 21:00:32 Incremental backup of volume '/usr'
10/05/07 21:00:32 Incremental backup of volume '/opt'
.
.
.
10/05/07 21:03:15 Successful incremental backup of '/dbu'
10/05/07 22:56:51 Successful incremental backup of '/dbb'
10/05/07 22:56:51 --- SCHEDULEREC STATUS BEGIN
10/05/07 22:56:51 Session established with server AIXTSM1: AIX-RS/6000
10/05/07 22:56:51 Server Version 5, Release 2, Level 4.4
10/05/07 22:56:51 Server date/time: 10/05/07 22:56:51 Last access: 10/05/07 21:03:20
10/05/07 22:56:51 Total number of objects inspected: 121,820
10/05/07 22:56:51 Total number of objects backed up: 768
10/05/07 22:56:51 Total number of objects updated: 1
10/05/07 22:56:51 Total number of objects rebound: 0
10/05/07 22:56:51 Total number of objects deleted: 0
10/05/07 22:56:51 Total number of objects expired: 297
10/05/07 22:56:51 Total number of objects failed: 0
10/05/07 22:56:51 Total number of bytes transferred: 186.92 GB
10/05/07 22:56:51 Data transfer time: 4,671.86 sec
10/05/07 22:56:51 Network data transfer rate: 41,955.16 KB/sec
10/05/07 22:56:51 Aggregate data transfer rate: 28,083.22 KB/sec
10/05/07 22:56:51 Objects compressed by: 0%
10/05/07 22:56:51 Elapsed processing time: 01:56:19
10/05/07 22:56:51 --- SCHEDULEREC STATUS END


Thanks for looking at this long email and for ur response.

--Barkath

 

[KevinADC]

have you tried removing this "last" loop controller?

   last; <---- this one
 }
 close INFILE;
}

------------------------------------------
- Kevin, perl coder unexceptional!

 

[barkath]

KevinADC,

Thanks for reply, tried removing "last" but still getting the same output.

 

[KevinADC]

Can't tell what the problem is because the sample data you posted has the ending pattern first, then the beginning pattern, then no end pattern.







------------------------------------------
- Kevin, perl coder unexceptional!

 

[barkath]

KevinADC,

Below is the actual log from 10/28 and 10/29, thanks again,

10/28/07 01:40:12 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/28/07 03:24:12 Retry # 1 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/28/07 05:42:18 Retry # 2 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/28/07 06:55:34 Retry # 3 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/28/07 08:05:17 Retry # 4 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/28/07 08:05:29 ANS1228E Sending of object '/dbb/ughpa/CACHE.DAT' failed
10/28/07 08:05:29 ANS4037E File '/dbb/ughpa/CACHE.DAT' changed during processing. File skipped.
10/28/07 08:15:26 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/28/07 08:20:21 Retry # 1 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/28/07 08:24:21 Retry # 2 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/28/07 08:32:40 Retry # 3 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/28/07 08:36:49 Retry # 4 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/28/07 08:36:51 ANS1228E Sending of object '/dbb/ugreg/CACHE.DAT' failed
10/28/07 08:36:51 ANS4037E File '/dbb/ugreg/CACHE.DAT' changed during processing. File skipped.
10/28/07 08:39:17 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/28/07 08:40:40 Retry # 1 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/28/07 08:41:39 Retry # 2 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/28/07 08:42:36 Retry # 3 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT [Sent]
10/28/07 08:42:36 ANS1802E Incremental backup of '/dbb' finished with 2 failure

10/28/07 08:42:36 --- SCHEDULEREC STATUS BEGIN
10/28/07 08:42:36 Session established with server AIXTSM1: AIX-RS/6000
10/28/07 08:42:36 Server Version 5, Release 2, Level 4.4
10/28/07 08:42:36 Server date/time: 10/28/07 08:42:36 Last access: 10/27/07 21:00:51

10/28/07 08:42:36 Total number of objects inspected: 122,079
10/28/07 08:42:36 Total number of objects backed up: 625
10/28/07 08:42:36 Total number of objects updated: 0
10/28/07 08:42:36 Total number of objects rebound: 0
10/28/07 08:42:36 Total number of objects deleted: 0
10/28/07 08:42:36 Total number of objects expired: 286
10/28/07 08:42:36 Total number of objects failed: 2
10/28/07 08:42:36 Total number of bytes transferred: 480.06 GB
10/28/07 08:42:36 Data transfer time: 23,535.23 sec
10/28/07 08:42:36 Network data transfer rate: 21,388.70 KB/sec
10/28/07 08:42:36 Aggregate data transfer rate: 11,951.63 KB/sec
10/28/07 08:42:36 Objects compressed by: 0%
10/28/07 08:42:36 Elapsed processing time: 11:41:58
10/28/07 08:42:36 --- SCHEDULEREC STATUS END
10/28/07 08:42:36 --- SCHEDULEREC OBJECT END CUSTOM_IDX_PART_1 10/27/07 21:00:00
10/28/07 08:42:36
Executing Operating System command or script:
/usr/local/sbin/check_dsmsched.pl
10/28/07 08:42:37 Finished command. Return code is: 0
10/28/07 08:42:37 Scheduled event 'CUSTOM_IDX_PART_1' completed successfully.
10/28/07 08:42:37 Sending results for scheduled event 'CUSTOM_IDX_PART_1'.
10/28/07 08:42:37 Session established with server AIXTSM1: AIX-RS/6000
10/28/07 08:42:37 Server Version 5, Release 2, Level 4.4
10/28/07 08:42:37 Server date/time: 10/28/07 08:42:37 Last access: 10/28/07 08:42:36

10/28/07 08:42:37 Results sent to server for scheduled event 'CUSTOM_IDX_PART_1'.

10/28/07 08:42:37 ANS1483I Schedule log pruning started.
10/28/07 08:42:37 ANS1484I Schedule log pruning finished successfully.
10/28/07 08:42:37 Querying server for next scheduled event.
10/28/07 08:42:37 Node Name: AIXIDX
10/28/07 08:42:38 Session established with server AIXTSM1: AIX-RS/6000
10/28/07 08:42:38 Server Version 5, Release 2, Level 4.4
10/28/07 08:42:38 Server date/time: 10/28/07 08:42:37 Last access: 10/28/07 08:42:37

10/28/07 08:42:38 --- SCHEDULEREC QUERY BEGIN
10/28/07 08:42:38 --- SCHEDULEREC QUERY END
10/28/07 08:42:38 Next operation scheduled:
10/28/07 08:42:38 ------------------------------------------------------------
10/28/07 08:42:38 Schedule Name: CUSTOM_IDX_PART_1
10/28/07 08:42:38 Action: Incremental
10/28/07 08:42:38 Objects: / /var /home /usr /opt /winshare /transfer /ftp /mjournal /dbu /arc /winshare2 /dbb
10/28/07 08:42:38 Options:
10/28/07 08:42:38 Server Window Start: 21:00:00 on 10/28/07
10/28/07 08:42:38 ------------------------------------------------------------
10/28/07 08:42:38 Waiting to be contacted by the server.
10/28/07 21:00:02 Querying server for next scheduled event.
10/28/07 21:00:02 Node Name: AIXIDX
10/28/07 21:00:02 Session established with server AIXTSM1: AIX-RS/6000
10/28/07 21:00:02 Server Version 5, Release 2, Level 4.4
10/28/07 21:00:02 Server date/time: 10/28/07 21:00:02 Last access: 10/28/07 08:42:37

10/28/07 21:00:02 --- SCHEDULEREC QUERY BEGIN
10/28/07 21:00:02 --- SCHEDULEREC QUERY END
10/28/07 21:00:02 Next operation scheduled:
10/28/07 21:00:02 ------------------------------------------------------------
10/28/07 21:00:02 Schedule Name: CUSTOM_IDX_PART_1
10/28/07 21:00:02 Action: Incremental
10/28/07 21:00:02 Objects: / /var /home /usr /opt /winshare /transfer /ftp /mjournal /dbu /arc /winshare2 /dbb
10/28/07 21:00:02 Options:
10/28/07 21:00:02 Server Window Start: 21:00:00 on 10/28/07
10/28/07 21:00:02 ------------------------------------------------------------
10/28/07 21:00:02
Executing scheduled command now.
10/28/07 21:00:02
Executing Operating System command or script:
/usr/local/sbin/backup_cache.pl
10/28/07 21:00:33 Finished command. Return code is: 0
10/28/07 21:00:34 --- SCHEDULEREC OBJECT BEGIN CUSTOM_IDX_PART_1 10/28/07 21:00:00
10/28/07 21:00:34 Incremental backup of volume '/'
10/28/07 21:00:34 Incremental backup of volume '/var'
10/28/07 21:00:34 Incremental backup of volume '/home'
10/28/07 21:00:34 Incremental backup of volume '/usr'
10/28/07 21:00:34 Incremental backup of volume '/opt'
10/28/07 21:00:34 Incremental backup of volume '/winshare'
10/28/07 21:00:34 Incremental backup of volume '/transfer'
10/28/07 21:00:34 Incremental backup of volume '/ftp'
10/28/07 21:00:34 Incremental backup of volume '/mjournal'
10/28/07 21:00:34 Incremental backup of volume '/dbu'
10/28/07 21:00:34 Incremental backup of volume '/arc'
10/28/07 21:00:34 Incremental backup of volume '/winshare2'
10/28/07 21:00:34 Incremental backup of volume '/dbb'

10/28/07 23:51:33 Normal File--> 117,755,084,800 /dbb/ugadt/CACHE.DAT [Sent]
10/29/07 00:02:25 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/29/07 00:12:50 Retry # 1 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/29/07 00:24:38 Retry # 2 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/29/07 00:27:27 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/29/07 00:34:03 Retry # 3 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/29/07 00:37:54 Retry # 4 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/29/07 00:37:56 ANS1228E Sending of object '/dbb/upgrade/CACHE.DAT' failed
10/29/07 00:37:56 ANS4037E File '/dbb/upgrade/CACHE.DAT' changed during processing. File skipped.
10/29/07 00:58:24 Retry # 1 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/29/07 01:27:24 Retry # 2 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/29/07 01:55:57 Retry # 3 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/29/07 02:05:41 Retry # 4 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/29/07 02:05:49 ANS1228E Sending of object '/dbb/ugreg/CACHE.DAT' failed
10/29/07 02:05:49 ANS4037E File '/dbb/ugreg/CACHE.DAT' changed during processing. File skipped.
10/29/07 02:51:43 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/29/07 04:24:08 Retry # 1 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/29/07 05:45:54 Retry # 2 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/29/07 06:47:56 Retry # 3 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/29/07 07:35:38 Retry # 4 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/29/07 07:35:48 ANS1228E Sending of object '/dbb/ughpa/CACHE.DAT' failed
10/29/07 07:35:48 ANS4037E File '/dbb/ughpa/CACHE.DAT' changed during processing. File skipped.
10/29/07 07:35:48 ANS1802E Incremental backup of '/dbb' finished with 3 failure

10/29/07 07:35:48 --- SCHEDULEREC STATUS BEGIN
10/29/07 07:35:48 Session established with server AIXTSM1: AIX-RS/6000
10/29/07 07:35:48 Server Version 5, Release 2, Level 4.4
10/29/07 07:35:48 Server date/time: 10/29/07 07:35:48 Last access: 10/28/07 23:51:44

10/29/07 07:35:48 Total number of objects inspected: 122,001
10/29/07 07:35:48 Total number of objects backed up: 657
10/29/07 07:35:48 Total number of objects updated: 0
10/29/07 07:35:48 Total number of objects rebound: 0
10/29/07 07:35:48 Total number of objects deleted: 0
10/29/07 07:35:48 Total number of objects expired: 349
10/29/07 07:35:48 Total number of objects failed: 3
10/29/07 07:35:48 Total number of bytes transferred: 483.47 GB
10/29/07 07:35:48 Data transfer time: 29,257.12 sec
10/29/07 07:35:48 Network data transfer rate: 17,327.75 KB/sec
10/29/07 07:35:48 Aggregate data transfer rate: 13,300.97 KB/sec
10/29/07 07:35:48 Objects compressed by: 0%
10/29/07 07:35:48 Elapsed processing time: 10:35:14
10/29/07 07:35:48 --- SCHEDULEREC STATUS END
10/29/07 07:35:48 --- SCHEDULEREC OBJECT END CUSTOM_IDX_PART_1 10/28/07 21:00:00
10/29/07 07:35:48
Executing Operating System command or script:
/usr/local/sbin/check_dsmsched.pl
10/29/07 07:35:49 Finished command. Return code is: 0
10/29/07 07:35:49 Scheduled event 'CUSTOM_IDX_PART_1' completed successfully.
10/29/07 07:35:49 Sending results for scheduled event 'CUSTOM_IDX_PART_1'.
10/29/07 07:35:49 Session established with server AIXTSM1: AIX-RS/6000
10/29/07 07:35:49 Server Version 5, Release 2, Level 4.4
10/29/07 07:35:49 Server date/time: 10/29/07 07:35:49 Last access: 10/29/07 07:35:48

10/29/07 07:35:49 Results sent to server for scheduled event 'CUSTOM_IDX_PART_1'.

10/29/07 07:35:49 ANS1483I Schedule log pruning started.
10/29/07 07:35:49 ANS1484I Schedule log pruning finished successfully.
10/29/07 07:35:49 Querying server for next scheduled event.
10/29/07 07:35:49 Node Name: AIXIDX
10/29/07 07:35:49 Session established with server AIXTSM1: AIX-RS/6000
10/29/07 07:35:49 Server Version 5, Release 2, Level 4.4
10/29/07 07:35:49 Server date/time: 10/29/07 07:35:49 Last access: 10/29/07 07:35:49

10/29/07 07:35:49 --- SCHEDULEREC QUERY BEGIN
10/29/07 07:35:49 --- SCHEDULEREC QUERY END
10/29/07 07:35:49 Next operation scheduled:
10/29/07 07:35:49 ------------------------------------------------------------
10/29/07 07:35:49 Schedule Name: CUSTOM_IDX_PART_1
10/29/07 07:35:49 Action: Incremental
10/29/07 07:35:49 Objects: / /var /home /usr /opt /winshare /transfer /ftp /mjournal /dbu /arc /winshare2 /dbb
10/29/07 07:35:49 Options:
10/29/07 07:35:49 Server Window Start: 21:00:00 on 10/29/07
10/29/07 07:35:49 ------------------------------------------------------------
10/29/07 07:35:49 Waiting to be contacted by the server.
10/29/07 21:00:02 Querying server for next scheduled event.
10/29/07 21:00:02 Node Name: AIXIDX
10/29/07 21:00:02 Session established with server AIXTSM1: AIX-RS/6000
10/29/07 21:00:02 Server Version 5, Release 2, Level 4.4
10/29/07 21:00:02 Server date/time: 10/29/07 21:00:02 Last access: 10/29/07 14:38:25

10/29/07 21:00:02 --- SCHEDULEREC QUERY BEGIN
10/29/07 21:00:02 --- SCHEDULEREC QUERY END
10/29/07 21:00:02 Next operation scheduled:
10/29/07 21:00:02 ------------------------------------------------------------
10/29/07 21:00:02 Schedule Name: CUSTOM_IDX_PART_1
10/29/07 21:00:02 Action: Incremental
10/29/07 21:00:02 Objects: / /var /home /usr /opt /winshare /transfer /ftp /mjournal /dbu /arc /winshare2 /dbb
10/29/07 21:00:02 Options:
10/29/07 21:00:02 Server Window Start: 21:00:00 on 10/29/07
10/29/07 21:00:02 ------------------------------------------------------------
10/29/07 21:00:02
Executing scheduled command now.
10/29/07 21:00:02
Executing Operating System command or script:
/usr/local/sbin/backup_cache.pl
10/29/07 21:00:31 Finished command. Return code is: 0
10/29/07 21:00:31 --- SCHEDULEREC OBJECT BEGIN CUSTOM_IDX_PART_1 10/29/07 21:00:00
10/29/07 21:00:31 Incremental backup of volume '/'
10/29/07 21:00:31 Incremental backup of volume '/var'
10/29/07 21:00:31 Incremental backup of volume '/home'
10/29/07 21:00:31 Incremental backup of volume '/usr'
10/29/07 21:00:31 Incremental backup of volume '/opt'
10/29/07 21:00:31 Incremental backup of volume '/winshare'
10/29/07 21:00:31 Incremental backup of volume '/transfer'
10/29/07 21:00:31 Incremental backup of volume '/ftp'
10/29/07 21:00:31 Incremental backup of volume '/mjournal'
10/29/07 21:00:31 Incremental backup of volume '/dbu'
10/29/07 21:00:31 Incremental backup of volume '/arc'
10/29/07 21:00:31 Incremental backup of volume '/winshare2'
10/29/07 21:00:31 Incremental backup of volume '/dbb'

10/29/07 21:12:36 Normal File--> 8,388,608,000 /dbb/ugiclaim/CACHE.DAT [Sent]
10/29/07 21:27:24 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/29/07 21:41:55 Retry # 1 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/29/07 21:57:22 Retry # 2 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/29/07 22:17:26 Retry # 3 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/29/07 22:34:35 Retry # 4 Normal File--> 11,010,048,000 /dbb/ugreg/CACHE.DAT Changed
10/29/07 22:35:09 ANS1228E Sending of object '/dbb/ugreg/CACHE.DAT' failed
10/29/07 22:35:09 ANS4037E File '/dbb/ugreg/CACHE.DAT' changed during processing. File skipped.
10/29/07 22:41:18 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/29/07 22:44:35 Retry # 1 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/29/07 22:47:40 Retry # 2 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/29/07 22:55:06 Retry # 3 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/29/07 22:59:01 Retry # 4 Normal File--> 3,670,016,000 /dbb/upgrade/CACHE.DAT Changed
10/29/07 22:59:02 ANS1228E Sending of object '/dbb/upgrade/CACHE.DAT' failed
10/29/07 22:59:02 ANS4037E File '/dbb/upgrade/CACHE.DAT' changed during processing. File skipped.
10/29/07 23:08:55 Normal File--> 65,011,712,000 /dbb/ughpa/CACHE.DAT Changed
10/29/07 23:44:38 Normal File--> 117,755,084,800 /dbb/ugadt/CACHE.DAT Changed