ADSM-L

Re: strange incremental behavior on Windows 5.2.2.0

2005-08-09 13:35:43
Subject: Re: strange incremental behavior on Windows 5.2.2.0
From: Andrew Raibeck <storman AT US.IBM DOT COM>
To: ADSM-L AT VM.MARIST DOT EDU
Date: Tue, 9 Aug 2005 10:35:35 -0700
Well, the ANS1304W message that immediately precedes the ending statistics
is suspicious.

What's in dsmerror.log?

Regards,

Andy

Andy Raibeck
IBM Software Group
Tivoli Storage Manager Client Development
Internal Notes e-mail: Andrew Raibeck/Tucson/IBM@IBMUS
Internet e-mail: storman AT us.ibm DOT com

The only dumb question is the one that goes unasked.
The command line is your friend.
"Good enough" is the enemy of excellence.

"ADSM: Dist Stor Manager" <ADSM-L AT VM.MARIST DOT EDU> wrote on 2005-08-09
10:19:28:

> Richard,
>
> yes & yes.
> q inclexcl & q opt show nothing out of the ordinary that I can see.
>
> here is the section of dsmsched.log from the scheduled backup:
> 08/07/2005 18:07:04 The Scheduler is under the control of the TSM
Scheduler
> Daemon
> 08/07/2005 18:07:04 Scheduler has been started by Dsmcad.
> 08/07/2005 18:07:04 Querying server for next scheduled event.
> 08/07/2005 18:07:05 Node Name: FRIENDSHIP
> 08/07/2005 18:07:05 Session established with server TSMPROD02:
AIX-RS/6000
> 08/07/2005 18:07:05   Server Version 5, Release 2, Level 2.0
> 08/07/2005 18:07:05   Server date/time: 08/07/2005 18:00:33  Last
access:
> 08/07/2005 18:00:25
>
> 08/07/2005 18:07:05 --- SCHEDULEREC QUERY BEGIN
> 08/07/2005 18:07:05 --- SCHEDULEREC QUERY END
> 08/07/2005 18:07:05 Next operation scheduled:
> 08/07/2005 18:07:06
> ------------------------------------------------------------
> 08/07/2005 18:07:06 Schedule Name:         INCR_1800
> 08/07/2005 18:07:06 Action:                Incremental
> 08/07/2005 18:07:06 Objects:
> 08/07/2005 18:07:06 Options:
> 08/07/2005 18:07:06 Server Window Start:   18:00:00 on 08/07/2005
> 08/07/2005 18:07:06
> ------------------------------------------------------------
> 08/07/2005 18:07:06
> Executing scheduled command now.
> 08/07/2005 18:07:06 --- SCHEDULEREC OBJECT BEGIN INCR_1800 08/07/2005
> 18:00:00
> 08/07/2005 18:07:06 Incremental backup of volume '\\friendship\c$'
> 08/07/2005 18:07:06 Incremental backup of volume '\\friendship\e$'
> 08/07/2005 18:07:06 Incremental backup of volume '\\friendship\f$'
> 08/07/2005 18:07:07 Incremental backup of volume '\\friendship\g$'
> 08/07/2005 18:07:07 Incremental backup of volume 'SYSTEMSTATE'
> 08/07/2005 18:07:07 Backup System State using shadow copy...
> 08/07/2005 18:07:08 Backup System State: 'System Files'.
>
> 08/07/2005 18:07:08 Backup System State: 'Registry'.
>
> 08/07/2005 18:07:08 Backup System State: 'COM+ Database'.
>
> 08/07/2005 18:09:48 Incremental backup of volume 'SYSTEMSERVICES'
> 08/07/2005 18:09:48 Backup System Services using shadow copy...
> 08/07/2005 18:09:50 Backup System Service: 'Event Log'.
>
> 08/07/2005 18:09:55 Backup System Service: 'WMI Database'.
>
> 08/07/2005 18:09:55 ANS1898I ***** Processed     3,500 files *****
> 08/07/2005 18:09:55 Successful incremental backup of '\\friendship\e$'
>
> 08/07/2005 18:09:55 Directory-->                   0 \\friendship\c$\
> <file://\\friendship\c$\>  [Sent]
> 08/07/2005 18:09:55 Directory-->                   0
> \\friendship\c$\adsm.sys <file://\\friendship\c$\adsm.sys>   Changed
> 08/07/2005 18:09:55 Normal File-->           200,704
> \\friendship\c$\Documents <file://\\friendship\c$\Documents>  and
> Settings\a66967k\NTUSER.DAT [Sent]
> 08/07/2005 18:09:56 Normal File-->             1,024
> \\friendship\c$\Documents <file://\\friendship\c$\Documents>  and
> Settings\a66967k\ntuser.dat.LOG [Sent]
> 08/07/2005 18:09:56 Normal File-->           524,288
> \\friendship\c$\Documents <file://\\friendship\c$\Documents>  and
> Settings\Administrator\NTUSER.DAT [Sent]
> 08/07/2005 18:09:56 Normal File-->             1,024
> \\friendship\c$\Documents <file://\\friendship\c$\Documents>  and
> Settings\Administrator\ntuser.dat.LOG [Sent]
> 08/07/2005 18:09:56 Normal File-->            16,583
> \\friendship\c$\Documents <file://\\friendship\c$\Documents>  and
> Settings\All Users\Application Data\Danware Data\NetOp Remote
> Control\HOST\comprof.ndb  ** Unsuccessful **
> .
> .
> .
> etc, etc, etc
> .
> .
> .
> 08/07/2005 18:11:43 Directory-->                   0
> \\friendship\c$\WINDOWS\Debug\UserMode
> <file://\\friendship\c$\WINDOWS\Debug\UserMode>   Changed
> 08/07/2005 18:11:43 Retry # 1  Directory-->                   0
> \\friendship\c$\WINDOWS\Debug\UserMode
> <file://\\friendship\c$\WINDOWS\Debug\UserMode>  [Sent]
> 08/07/2005 18:11:43 Retry # 1  Normal File-->         2,477,611
> \\friendship\c$\Program <file://\\friendship\c$\Program>
> Files\Tivoli\TSM\baclient\dsmerror.log  Changed
> 08/07/2005 18:11:43 Retry # 2  Normal File-->         2,477,990
> \\friendship\c$\Program <file://\\friendship\c$\Program>
> Files\Tivoli\TSM\baclient\dsmerror.log  Changed
> 08/07/2005 18:11:43 ANS1802E Incremental backup of '\\friendship\c$'
> finished with 29 failure
>
> 08/07/2005 18:11:44 Successful incremental backup of '\\friendship\f$'
>
> 08/07/2005 18:11:44 Successful incremental backup of '\\friendship\g$'
>
> 08/07/2005 18:11:45 ANS1898I ***** Processed     9,500 files *****
> 08/07/2005 18:11:45 ANS1304W Active object not found
>
> 08/07/2005 18:11:45 --- SCHEDULEREC STATUS BEGIN
> 08/07/2005 18:11:46 Total number of objects inspected:    9,829
> 08/07/2005 18:11:46 Total number of objects backed up:      262
> 08/07/2005 18:11:46 Total number of objects updated:          0
> 08/07/2005 18:11:46 Total number of objects rebound:          0
> 08/07/2005 18:11:46 Total number of objects deleted:          0
> 08/07/2005 18:11:46 Total number of objects expired:          5
> 08/07/2005 18:11:46 Total number of objects failed:          29
> 08/07/2005 18:11:46 Total number of bytes transferred:    83.70 MB
> 08/07/2005 18:11:46 Data transfer time:                   33.81 sec
> 08/07/2005 18:11:46 Network data transfer rate:        2,535.23 KB/sec
> 08/07/2005 18:11:46 Aggregate data transfer rate:        307.19 KB/sec
> 08/07/2005 18:11:46 Objects compressed by:                    0%
> 08/07/2005 18:11:46 Elapsed processing time:           00:04:39
> 08/07/2005 18:11:46 --- SCHEDULEREC STATUS END
> 08/07/2005 18:11:46 --- SCHEDULEREC OBJECT END INCR_1800 08/07/2005
18:00:00
> 08/07/2005 18:11:47 Scheduled event 'INCR_1800' completed successfully.
> 08/07/2005 18:11:47 Sending results for scheduled event 'INCR_1800'.
> 08/07/2005 18:11:47 Results sent to server for scheduled event
'INCR_1800'.
>
> 08/07/2005 18:11:47 ANS1483I Schedule log pruning started.
> 08/07/2005 18:11:56 ANS1484I Schedule log pruning finished successfully.
> 08/07/2005 18:11:56 Querying server for next scheduled event.
> 08/07/2005 18:11:56 Node Name: FRIENDSHIP
> 08/07/2005 18:11:56 Session established with server TSMPROD02:
AIX-RS/6000
> 08/07/2005 18:11:56   Server Version 5, Release 2, Level 2.0
> 08/07/2005 18:11:56   Server date/time: 08/07/2005 18:05:24  Last
access:
> 08/07/2005 18:04:14
>
> 08/07/2005 18:11:56 --- SCHEDULEREC QUERY BEGIN
> 08/07/2005 18:11:57 --- SCHEDULEREC QUERY END
> 08/07/2005 18:11:57 Next operation scheduled:
> 08/07/2005 18:11:57
> ------------------------------------------------------------
> 08/07/2005 18:11:57 Schedule Name:         INCR_1800
> 08/07/2005 18:11:57 Action:                Incremental
> 08/07/2005 18:11:57 Objects:
> 08/07/2005 18:11:57 Options:
> 08/07/2005 18:11:57 Server Window Start:   18:00:00 on 08/08/2005
> 08/07/2005 18:11:57
> ------------------------------------------------------------
> 08/07/2005 18:11:57 Scheduler has been stopped.
>
>
>   _____
>
> From: Richard Cowen [mailto:richard.cowen AT mcdata DOT com]
> Sent: Tuesday, August 09, 2005 12:14 PM
> To: Schaub, Steve
> Subject: RE: [ADSM-L] strange incremental behavior on Windows 5.2.2.0
>
>
> Steve-
>
> When you use the command line, do some files get backed up?
> Do filespaces seem to be "seen"?
> With a command line client, what does query inclexcl show?
>
>   _____
>
> From: ADSM: Dist Stor Manager on behalf of Steve Schaub
> Sent: Tue 8/9/2005 10:09 AM
> To: ADSM-L AT VM.MARIST DOT EDU
> Subject: [ADSM-L] strange incremental behavior on Windows 5.2.2.0
>
>
>
> TSM server 5.2.2.0 on AIX, client 5.2.2.0 on Win 2003 Std
>
> About 2 weeks ago we noticed that the daily scheduled incremental
backups on
> our 2 big fileservers were behaving oddly.
>
> When the scheduled incrementals run, or if I use an immediate action, or
> command line from the machines themselves, the backups look like they
> complete normally, but they only show that they have examined < 10k
files.
> There is no error message in the sched log or the activity log, nothing
in
> dsmerror or dsierror, no dump, nothing.  the schedule reports completed
> successfully.
>
> If I termserv to the machines and backup through the client gui, it
behaves
> normally and backs up tons of files.
>
> These file servers each have 2 volumes of 1.7TB and 1.3TB with over 5mil
> files on each.  These volumes have been increased every few weeks due to
> running out of space.
>
> I havent found any apar that seems to fit this odd behavior, and we
havent
> touched the tsm client on these machines for at least 6 months.  we are
not
> using journaling on them.
>
> anyone seen anything that would shed light?
>
> Steve Schaub
> Systems Engineer, WNI
> BlueCross BlueShield of Tennessee
> 423-752-6574 (desk)
> 423-785-7347 (cell)
>
> Please see the following link for the BlueCross BlueShield of Tennessee
> E-mail
> disclaimer:  http://www.bcbst.com/email_disclaimer.shtm
> <http://www.bcbst.com/email_disclaimer.shtm>
>
>
> Please see the following link for the BlueCross BlueShield of Tennessee
E-mail
> disclaimer:  http://www.bcbst.com/email_disclaimer.shtm