ADSM-L
[Top] [All Lists]
<prev [Date] next>
[Advanced]
 <prev [Thread] next>

Re: strange incremental behavior on Windows 5.2.2.0

2005-08-09 14:11:32
Subject: Re: strange incremental behavior on Windows 5.2.2.0
From: Steve Schaub <Steve_Schaub AT BCBST DOT COM>
To: ADSM-L AT VM.MARIST DOT EDU
Date: Tue, 9 Aug 2005 14:10:52 -0400 
Andy,

Here is the dsmerror.log snipped from the same time period:
08/07/2005 18:10:05 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Mission Critical
Software\OnePoint\BCBSTSERVERS\EvtCons' failed
08/07/2005 18:10:06 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Mission Critical
Software\OnePoint\BCBSTSERVERS\EvtSend.pqf' failed
08/07/2005 18:10:06 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Mission Critical
Software\OnePoint\BCBSTSERVERS\EvtSend.pqf': the object is in use by another
process
08/07/2005 18:10:08 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Mission Critical
Software\OnePoint\BCBSTSERVERS\ExtSubmit.pqf' failed
08/07/2005 18:10:08 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Mission Critical
Software\OnePoint\BCBSTSERVERS\ExtSubmit.pqf': the object is in use by
another process
08/07/2005 18:10:36 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\DirServ.ndb' failed
08/07/2005 18:10:37 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\DirServ.ndb': the object is in use by another process
08/07/2005 18:10:39 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\gwscrty.ndb' failed
08/07/2005 18:10:39 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\gwscrty.ndb': the object is in use by another process
08/07/2005 18:10:40 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\gwscr_NT.ndb' failed
08/07/2005 18:10:40 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\gwscr_NT.ndb': the object is in use by another process
08/07/2005 18:10:44 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\modems.ndb' failed
08/07/2005 18:10:45 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\modems.ndb': the object is in use by another process
08/07/2005 18:10:46 gtUpdateGroupAttr() server error 4 on update SYSTEM
STATE\SYSFILES
08/07/2005 18:10:46 Mutex lock failed: 6.
08/07/2005 18:10:46 Acquire Mutex failed: invalid mutex.
08/07/2005 18:10:47 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\nhstconf.ndb' failed
08/07/2005 18:10:47 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\nhstconf.ndb': the object is in use by another process
08/07/2005 18:10:48 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\NetworkService\Local Settings\Application
Data\Microsoft\Windows\UsrClass.dat' failed
08/07/2005 18:10:48 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\NetworkService\Local Settings\Application
Data\Microsoft\Windows\UsrClass.dat': the object is in use by another
process
08/07/2005 18:10:50 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\security.ndb' failed
08/07/2005 18:10:50 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\security.ndb': the object is in use by another process
08/07/2005 18:10:50 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\NetworkService\Local Settings\Application
Data\Microsoft\Windows\UsrClass.dat.LOG' failed
08/07/2005 18:10:50 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\NetworkService\Local Settings\Application
Data\Microsoft\Windows\UsrClass.dat.LOG': the object is in use by another
process
08/07/2005 18:10:51 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\secur_DS.ndb' failed
08/07/2005 18:10:51 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\secur_DS.ndb': the object is in use by another process
08/07/2005 18:10:53 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\secur_NT.ndb' failed
08/07/2005 18:10:53 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Danware Data\NetOp Remote
Control\HOST\secur_NT.ndb': the object is in use by another process
08/07/2005 18:10:56 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Mission Critical
Software\OnePoint\BCBSTSERVERS\AgentResponseMgr.pqf' failed
08/07/2005 18:10:56 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Mission Critical
Software\OnePoint\BCBSTSERVERS\AgentResponseMgr.pqf': the object is in use
by another process
08/07/2005 18:10:56 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\LocalService\NTUSER.DAT' failed
08/07/2005 18:10:56 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\LocalService\NTUSER.DAT': the object is in use by another process
08/07/2005 18:10:59 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\LocalService\ntuser.dat.LOG' failed
08/07/2005 18:10:59 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\LocalService\ntuser.dat.LOG': the object is in use by another
process
08/07/2005 18:10:59 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\All Users\Application Data\Mission Critical
Software\OnePoint\BCBSTSERVERS\AlertSend.pqf' failed
08/07/2005 18:10:59 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\All Users\Application Data\Mission Critical
Software\OnePoint\BCBSTSERVERS\AlertSend.pqf': the object is in use by
another process
08/07/2005 18:11:01 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\LocalService\Local Settings\Application
Data\Microsoft\Windows\UsrClass.dat' failed
08/07/2005 18:11:01 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\LocalService\Local Settings\Application
Data\Microsoft\Windows\UsrClass.dat': the object is in use by another
process
08/07/2005 18:11:03 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\LocalService\Local Settings\Application
Data\Microsoft\Windows\UsrClass.dat.LOG' failed
08/07/2005 18:11:03 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\LocalService\Local Settings\Application
Data\Microsoft\Windows\UsrClass.dat.LOG': the object is in use by another
process
08/07/2005 18:11:03 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\s42919s2\NTUSER.DAT' failed
08/07/2005 18:11:03 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\s42919s2\NTUSER.DAT': the object is in use by another process
08/07/2005 18:11:05 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\s42919s2\ntuser.dat.LOG' failed
08/07/2005 18:11:05 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\s42919s2\ntuser.dat.LOG': the object is in use by another process
08/07/2005 18:11:07 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\NetworkService\NTUSER.DAT' failed
08/07/2005 18:11:07 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\NetworkService\NTUSER.DAT': the object is in use by another process
08/07/2005 18:11:16 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\SMSCliSvcAcct&\NTUSER.DAT' failed
08/07/2005 18:11:16 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\SMSCliSvcAcct&\NTUSER.DAT': the object is in use by another process
08/07/2005 18:11:16 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\s42919s2\Local Settings\Application
Data\Microsoft\Windows\UsrClass.dat.LOG' failed
08/07/2005 18:11:16 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\s42919s2\Local Settings\Application
Data\Microsoft\Windows\UsrClass.dat.LOG': the object is in use by another
process
08/07/2005 18:11:16 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\NetworkService\ntuser.dat.LOG' failed
08/07/2005 18:11:17 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\NetworkService\ntuser.dat.LOG': the object is in use by another
process
08/07/2005 18:11:18 ANS1228E Sending of object '\\friendship\c$\Documents
and Settings\SMSCliSvcAcct&\ntuser.dat.LOG' failed
08/07/2005 18:11:18 ANS4987E Error processing '\\friendship\c$\Documents and
Settings\SMSCliSvcAcct&\ntuser.dat.LOG': the object is in use by another
process
08/07/2005 18:11:39 ANS1228E Sending of object '\\friendship\c$\Program
Files\IBM\Director\data\esntevt.dat' failed
08/07/2005 18:11:39 ANS4037E File '\\friendship\c$\Program
Files\IBM\Director\data\esntevt.dat' changed during processing.  File
skipped.
08/07/2005 18:11:43 ANS1802E Incremental backup of '\\friendship\c$'
finished with 29 failure

08/07/2005 18:11:44 ANS1802E Incremental backup of '\\friendship\c$'
finished with 29 failure

08/07/2005 18:11:45 ANS1304W Active object not found

-----Original Message-----
From: ADSM: Dist Stor Manager [mailto:ADSM-L AT VM.MARIST DOT EDU] On Behalf Of
Andrew Raibeck
Sent: Tuesday, August 09, 2005 1:36 PM
To: ADSM-L AT VM.MARIST DOT EDU
Subject: Re: [ADSM-L] strange incremental behavior on Windows 5.2.2.0

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
Please see the following link for the BlueCross BlueShield of Tennessee E-mail
disclaimer:  http://www.bcbst.com/email_disclaimer.shtm
[More with this subject...]
<Prev in Thread] Current Thread [Next in Thread>
Previous by Date:  TSM for DR and Content Manager, Karin Dambacher
Next by Date:  Re: strange incremental behavior on Windows 5.2.2.0, Richard Cowen
Previous by Thread:  Re: strange incremental behavior on Windows 5.2.2.0, David E Ehresman
Next by Thread:  Re: strange incremental behavior on Windows 5.2.2.0, Richard Cowen
Indexes:  [Date] [Thread] [Top] [All Lists]