Failed Notices

rich872

ADSM.ORG Member
Joined
Dec 13, 2007
Messages
5
Reaction score
0
Points
0
I recently upgraded one of our Tivoli clients to 5.5 from 5.1 to resolve a known issue. That issue is now resolved but now for some reason, we are getting a failed backup notice for that server when the backup was actually successful. I've looked at logs and everything looks fine, the backups are going through successfully yet we are still getting failed backup notices. This is the first time we have used 5.5, I'm thinking about reverting back to 5.34 like most of our other servers but wanted to get another opinion first. Thanks!
 
Below is the entire dsmerror.log entry from last nights backup. There were a few files open but that has never caused a failed backup notice before. This is a file server and usually its many more files open than this.

12/13/2007 02:25:51 ANS1228E Sending of object '\\mwh-fs2\f$\DATA\USERS\WAMNMMM\outlook.ost' failed
12/13/2007 02:25:51 ANS4987E Error processing '\\mwh-fs2\f$\DATA\USERS\WAMNMMM\outlook.ost': the object is in use by another process
12/13/2007 02:51:17 ANS1228E Sending of object '\\mwh-fs2\f$\DATA\USERS\WCEFSKL\outlook2.ost' failed
12/13/2007 02:51:17 ANS4987E Error processing '\\mwh-fs2\f$\DATA\USERS\WCEFSKL\outlook2.ost': the object is in use by another process
12/13/2007 02:51:17 ANS1228E Sending of object '\\mwh-fs2\f$\DATA\USERS\WCEFSKL\Personal Folders 1.pst' failed
12/13/2007 02:51:17 ANS4987E Error processing '\\mwh-fs2\f$\DATA\USERS\WCEFSKL\Personal Folders 1.pst': the object is in use by another process
12/13/2007 03:57:16 ANS1802E Incremental backup of '\\mwh-fs2\f$' finished with 3 failure

12/13/2007 03:57:16 ANS1802E Incremental backup of '\\mwh-fs2\f$' finished with 3 failure
 
Hi.

That is pretty typical obviously for a file server to miss a couple of files. We also have PST files failing here, due to the fact that they are open by the user's OUtlook session...

What about the dsmsched.log ? It should contain the failure return code since you mention you get Failed backups...

11/15/2007 22:54:16 --- SCHEDULEREC STATUS BEGIN
11/15/2007 22:54:16 Total number of objects inspected: 544,540
11/15/2007 22:54:16 Total number of objects backed up: 1,993
11/15/2007 22:54:16 Total number of objects updated: 0
11/15/2007 22:54:16 Total number of objects rebound: 0
11/15/2007 22:54:16 Total number of objects deleted: 0
11/15/2007 22:54:16 Total number of objects expired: 410
11/15/2007 22:54:16 Total number of objects failed: 0
11/15/2007 22:54:16 Total number of subfile objects: 0
11/15/2007 22:54:16 Total number of bytes transferred: 3.80 GB
11/15/2007 22:54:16 Data transfer time: 120.84 sec
11/15/2007 22:54:16 Network data transfer rate: 32,988.19 KB/sec
11/15/2007 22:54:16 Aggregate data transfer rate: 670.39 KB/sec
11/15/2007 22:54:16 Objects compressed by: 0%
11/15/2007 22:54:16 Subfile objects reduced by: 0%
11/15/2007 22:54:16 Elapsed processing time: 01:39:06
11/15/2007 22:54:16 --- SCHEDULEREC STATUS END
11/15/2007 22:54:16 --- SCHEDULEREC OBJECT END NT_INCR_A 11/15/2007 21:15:00
11/15/2007 22:54:16 ANS1512E Scheduled event 'NT_INCR_A' failed. Return code = 12.
11/15/2007 22:54:16 Sending results for scheduled event 'NT_INCR_A'.
11/15/2007 22:54:16 Results sent to server for scheduled event 'NT_INCR_A'.

Here, my problem was that i had a restartable session hanging...

11/15/2007 22:54:15 ANS1330S This node currently has a pending restartable restore session.
The requested operation cannot complete until this session either
completes or is canceled.
11/15/2007 22:54:16
System State Backup finished with failures.
11/15/2007 22:54:16
System Services Backup finished with failures.
 
Below is the entry for last night:

12/13/2007 01:48:30 --- SCHEDULEREC QUERY BEGIN
12/13/2007 01:48:30 --- SCHEDULEREC QUERY END
12/13/2007 01:48:30 Next operation scheduled:
12/13/2007 01:48:30 ------------------------------------------------------------
12/13/2007 01:48:30 Schedule Name: WIN_10PM
12/13/2007 01:48:30 Action: Incremental
12/13/2007 01:48:30 Objects:
12/13/2007 01:48:30 Options:
12/13/2007 01:48:30 Server Window Start: 22:00:00 on 12/12/2007
12/13/2007 01:48:30 ------------------------------------------------------------
12/13/2007 01:48:30
Executing scheduled command now.
12/13/2007 01:48:30 --- SCHEDULEREC OBJECT BEGIN WIN_10PM 12/12/2007 22:00:00
12/13/2007 01:48:30 Incremental backup of volume '\\mwh-fs2\e$'
12/13/2007 01:48:30 Incremental backup of volume '\\mwh-fs2\f$'
12/13/2007 01:48:30 Incremental backup of volume 'SYSTEMSTATE'
12/13/2007 01:48:40 Performing a full, TSM backup of object 'COM+ REGDB Writer' component 'COM+ REGDB' using shadow copy.
12/13/2007 01:48:40 Performing a full, TSM backup of object 'Registry Writer' component 'Registry' using shadow copy.
12/13/2007 01:48:40 Performing a full, TSM backup of object 'System Writer' component 'System Files' using shadow copy.
12/13/2007 01:49:25 Performing a full, TSM backup of object 'Event Log Writer' component 'Event Logs' using shadow copy.
12/13/2007 01:49:26 Performing a full, TSM backup of object 'IIS Metabase Writer' component 'IISMETABASE' using shadow copy.
12/13/2007 01:49:26 Performing a full, TSM backup of object 'WMI Writer' component 'Windows Managment Instrumentation' using shadow copy.
12/13/2007 01:50:44 Backup of object 'SystemState' component 'System State' finished successfully.
12/13/2007 01:50:46 Successful incremental backup of 'MWH-FS2\SystemState\NULL\System State\SystemState'
12/13/2007 01:50:47 Successful incremental backup of 'Automated System Recovery'
12/13/2007 02:25:51 ANS1228E Sending of object '\\mwh-fs2\f$\DATA\USERS\WAMNMMM\outlook.ost' failed
12/13/2007 02:25:51 ANS4987E Error processing '\\mwh-fs2\f$\DATA\USERS\WAMNMMM\outlook.ost': the object is in use by another process
12/13/2007 02:51:17 ANS1228E Sending of object '\\mwh-fs2\f$\DATA\USERS\WCEFSKL\outlook2.ost' failed
12/13/2007 02:51:17 ANS4987E Error processing '\\mwh-fs2\f$\DATA\USERS\WCEFSKL\outlook2.ost': the object is in use by another process
12/13/2007 02:51:17 ANS1228E Sending of object '\\mwh-fs2\f$\DATA\USERS\WCEFSKL\Personal Folders 1.pst' failed
12/13/2007 02:51:17 ANS4987E Error processing '\\mwh-fs2\f$\DATA\USERS\WCEFSKL\Personal Folders 1.pst': the object is in use by another process
12/13/2007 03:57:16 ANS1802E Incremental backup of '\\mwh-fs2\f$' finished with 3 failure
12/13/2007 03:57:49 Successful incremental backup of '\\mwh-fs2\e$'
12/13/2007 03:57:51 --- SCHEDULEREC STATUS BEGIN
12/13/2007 03:57:51 Total number of objects inspected: 564,313
12/13/2007 03:57:51 Total number of objects backed up: 1,136
12/13/2007 03:57:51 Total number of objects updated: 0
12/13/2007 03:57:51 Total number of objects rebound: 0
12/13/2007 03:57:51 Total number of objects deleted: 0
12/13/2007 03:57:51 Total number of objects expired: 44
12/13/2007 03:57:51 Total number of objects failed: 3
12/13/2007 03:57:51 Total number of subfile objects: 0
12/13/2007 03:57:51 Total number of bytes transferred: 30.37 GB
12/13/2007 03:57:51 Data transfer time: 4,846.26 sec
12/13/2007 03:57:51 Network data transfer rate: 6,572.50 KB/sec
12/13/2007 03:57:51 Aggregate data transfer rate: 4,104.34 KB/sec
12/13/2007 03:57:51 Objects compressed by: 0%
12/13/2007 03:57:51 Subfile objects reduced by: 0%
12/13/2007 03:57:51 Elapsed processing time: 02:09:20
12/13/2007 03:57:51 --- SCHEDULEREC STATUS END
12/13/2007 03:57:51 --- SCHEDULEREC OBJECT END WIN_10PM 12/12/2007 22:00:00
12/13/2007 03:57:51 Scheduled event 'WIN_10PM' completed successfully.
12/13/2007 03:57:51 Sending results for scheduled event 'WIN_10PM'.
12/13/2007 03:57:51 Results sent to server for scheduled event 'WIN_10PM'.
12/13/2007 03:57:51 ANS1483I Schedule log pruning started.
12/13/2007 03:57:51 ANS1484I Schedule log pruning finished successfully.
12/13/2007 03:57:51 TSM Backup-Archive Client Version 5, Release 5, Level 0.0
12/13/2007 03:57:51 Querying server for next scheduled event.
12/13/2007 03:57:51 Node Name: MWH-FS2
12/13/2007 03:57:51 Session established with server TSM5.3: AIX-RS/6000
12/13/2007 03:57:51 Server Version 5, Release 3, Level 6.0
12/13/2007 03:57:51 Server date/time: 12/13/2007 03:56:02 Last access: 12/13/2007 01:47:44
12/13/2007 03:57:51 --- SCHEDULEREC QUERY BEGIN
12/13/2007 03:57:51 --- SCHEDULEREC QUERY END
12/13/2007 03:57:51 Next operation scheduled:
12/13/2007 03:57:51 ------------------------------------------------------------
12/13/2007 03:57:51 Schedule Name: WIN_10PM
12/13/2007 03:57:51 Action: Incremental
12/13/2007 03:57:51 Objects:
12/13/2007 03:57:51 Options:
12/13/2007 03:57:51 Server Window Start: 22:00:00 on 12/13/2007
12/13/2007 03:57:51 ------------------------------------------------------------
12/13/2007 03:57:51 Schedule will be refreshed in 12 hours.
 
Huh? You get a failed backup for this? Your logs clearly show:

12/13/2007 03:57:51 Scheduled event 'WIN_10PM' completed successfully.

What is giving you the Failed backup status? the TSM reporting tool?
 
Yep, there is no reason they should be getting a failed backup notice yet they are. The TSM reporting tool is giving the failed backup notices. Talking to one of my co-workers he believes it could be a compatibility issue between the client (5.5) and the server (5.3). He suggests I revert to the 5.34 client. Probably will do that just wanted to run it by you guys to know if there is anything else I can check or do.
 
I have seen this also. We have not found a reason why its doing this. I have seen this since 5.4.

12/12/2007 02:02:02 ANS1512E Scheduled event 'DAILY_INCR' failed. Return code = 12.
12/12/2007 22:43:35 ANS1228E Sending of object '\\stlfs3\f$\Users\MWaters\archive.pst' failed
12/12/2007 22:43:36 ANS4007E Error processing '\\stlfs3\f$\Users\MWaters\archive.pst': access to the object is denied
12/12/2007 22:43:37 ANS1228E Sending of object '\\stlfs3\f$\Users\MWaters\mail\archive.pst' failed
12/12/2007 22:43:37 ANS4007E Error processing '\\stlfs3\f$\Users\MWaters\mail\archive.pst': access to the object is denied
12/12/2007 22:43:37 ANS1228E Sending of object '\\stlfs3\f$\Users\MWaters\mail\archiveold.pst' failed
12/12/2007 22:43:37 ANS4007E Error processing '\\stlfs3\f$\Users\MWaters\mail\archiveold.pst': access to the object is denied
12/12/2007 23:20:34 ANS1802E Incremental backup of '\\stlfs3\f$' finished with 3 failure

12/12/2007 23:20:34 ANS1802E Incremental backup of '\\stlfs3\f$' finished with 3 failure

12/12/2007 23:20:39 --- SCHEDULEREC STATUS BEGIN
12/12/2007 23:20:39 Total number of objects inspected: 2,135,007
12/12/2007 23:20:39 Total number of objects backed up: 6,053
12/12/2007 23:20:39 Total number of objects updated: 5
12/12/2007 23:20:40 Total number of objects rebound: 0
12/12/2007 23:20:40 Total number of objects deleted: 0
12/12/2007 23:20:40 Total number of objects expired: 6,234
12/12/2007 23:20:40 Total number of objects failed: 3
12/12/2007 23:20:40 Total number of subfile objects: 0
12/12/2007 23:20:40 Total number of bytes transferred: 199.46 GB
12/12/2007 23:20:40 Data transfer time: 24,800.80 sec
12/12/2007 23:20:40 Network data transfer rate: 8,433.37 KB/sec
12/12/2007 23:20:40 Aggregate data transfer rate: 10,494.06 KB/sec
12/12/2007 23:20:40 Objects compressed by: 0%
12/12/2007 23:20:40 Subfile objects reduced by: 0%
12/12/2007 23:20:40 Elapsed processing time: 05:32:10
12/12/2007 23:20:40 --- SCHEDULEREC STATUS END
12/12/2007 23:20:40 --- SCHEDULEREC OBJECT END DAILY_INCR 12/12/2007 17:00:00
12/12/2007 23:20:40 Scheduled event 'DAILY_INCR' completed successfully.
12/12/2007 23:20:40 Sending results for scheduled event 'DAILY_INCR'.
12/12/2007 23:20:40 Results sent to server for scheduled event 'DAILY_INCR'.
 
Whats your serialization parameter set to in your copy group ?
Have you installed open-file support ?
 
What does:
q event * WIN_10PM node=MWH-FS2 f=d
say? This will give us the actual return code which I'm guessing will be 12.

I'd check your activity log ("q act" on the server) for any other messages as well during the time of that backup (try using q act begind=-1 search=MWH-FS2).

I've seen the same thing myself, for some reason some nodes class some file missed type errors as a failure of the entire backup, rather than just a missed file. For example, "ANS4047E There is a read error on 'xxxxx'" seems to usually cause the backup to be classed as "failed" (RC=12) rather than missed files (RC=4).
 
I have seen this also. We have not found a reason why its doing this. I have seen this since 5.4.

12/12/2007 02:02:02 ANS1512E Scheduled event 'DAILY_INCR' failed. Return code = 12.
12/12/2007 22:43:35 ANS1228E Sending of object '\\stlfs3\f$\Users\MWaters\archive.pst' failed
12/12/2007 22:43:36 ANS4007E Error processing '\\stlfs3\f$\Users\MWaters\archive.pst': access to the object is denied
12/12/2007 22:43:37 ANS1228E Sending of object '\\stlfs3\f$\Users\MWaters\mail\archive.pst' failed
12/12/2007 22:43:37 ANS4007E Error processing '\\stlfs3\f$\Users\MWaters\mail\archive.pst': access to the object is denied
12/12/2007 22:43:37 ANS1228E Sending of object

Are you sure this isn't the old "security team thought it'd be a good idea to disable mail account and file access to members of security groups they didn't recongise and therefore cut off the account TSM runs under from PST files in Users' home directories" trick?
 
What does the server's activity log report for these backups?
ANR2507 (successful) or ANR2579 (failed)?
 
I'm having the same problems as the OP, funny thing is i have around 20 servers with the same schedule, backup server and TSM client version, but only a hand full is "failing".

TSM Client is 5.5.02 upgrade from 5.2.

01/30/2008 20:52:13 --- SCHEDULEREC QUERY BEGIN
01/30/2008 20:52:13 --- SCHEDULEREC QUERY END
01/30/2008 20:52:13 Next operation scheduled:
01/30/2008 20:52:13 ------------------------------------------------------------
01/30/2008 20:52:13 Schedule Name: DAILY_INC
01/30/2008 20:52:13 Action: Incremental
01/30/2008 20:52:13 Objects:
01/30/2008 20:52:13 Options:
01/30/2008 20:52:13 Server Window Start: 20:00:00 on 01/30/2008
01/30/2008 20:52:13 ------------------------------------------------------------
01/30/2008 20:52:13
Executing scheduled command now.
01/30/2008 20:52:14 --- SCHEDULEREC OBJECT BEGIN DAILY_INC 01/30/2008 20:00:00
01/30/2008 20:52:15 Incremental backup of volume '\\server1\c$'
01/30/2008 20:52:15 Incremental backup of volume 'SYSTEMSTATE'
01/30/2008 20:52:36 Performing a full, TSM backup of object 'COM+ REGDB Writer' component 'COM+ REGDB' using shadow copy.
01/30/2008 20:52:38 Performing a full, TSM backup of object 'Registry Writer' component 'Registry' using shadow copy.
01/30/2008 20:52:38 Performing a full, TSM backup of object 'System Writer' component 'System Files' using shadow copy.
01/30/2008 20:52:45 Performing a full, TSM backup of object 'Event Log Writer' component 'Event Logs' using shadow copy.
01/30/2008 20:52:46 Performing a full, TSM backup of object 'IIS Metabase Writer' component 'IISMETABASE' using shadow copy.
01/30/2008 20:52:47 Performing a full, TSM backup of object 'WMI Writer' component 'Windows Managment Instrumentation' using shadow copy.
01/30/2008 20:52:53 Preparing to backup using snapshot.
01/30/2008 20:53:08 Comparing local system files with active version on the server. This may take a long time depending on the number of files...

01/30/2008 21:23:35 Backup of object 'SystemState' component 'System State' finished successfully.
01/30/2008 21:23:38 Successful incremental backup of 'server1\SystemState\NULL\System State\SystemState'
01/30/2008 21:23:41 Successful incremental backup of 'Automated System Recovery'
01/30/2008 21:37:26 Successful incremental backup of '\\server1\c$'

01/30/2008 21:37:28 --- SCHEDULEREC STATUS BEGIN
01/30/2008 21:37:29 Total number of objects inspected: 139,990
01/30/2008 21:37:29 Total number of objects backed up: 175
01/30/2008 21:37:29 Total number of objects updated: 0
01/30/2008 21:37:29 Total number of objects rebound: 0
01/30/2008 21:37:29 Total number of objects deleted: 0
01/30/2008 21:37:29 Total number of objects expired: 21
01/30/2008 21:37:29 Total number of objects failed: 0
01/30/2008 21:37:29 Total number of subfile objects: 0
01/30/2008 21:37:29 Total number of bytes transferred: 104.14 MB
01/30/2008 21:37:29 Data transfer time: 14.38 sec
01/30/2008 21:37:29 Network data transfer rate: 7,412.30 KB/sec
01/30/2008 21:37:29 Aggregate data transfer rate: 39.29 KB/sec
01/30/2008 21:37:29 Objects compressed by: 58%
01/30/2008 21:37:29 Subfile objects reduced by: 0%
01/30/2008 21:37:29 Elapsed processing time: 00:45:14
01/30/2008 21:37:29 --- SCHEDULEREC STATUS END
01/30/2008 21:37:29 --- SCHEDULEREC OBJECT END DAILY_INC 01/30/2008 20:00:00
01/30/2008 21:37:29 Scheduled event 'DAILY_INC' completed successfully.
01/30/2008 21:37:29 Sending results for scheduled event 'DAILY_INC'.
01/30/2008 21:37:29 Results sent to server for scheduled event 'DAILY_INC'.
Yet the report tool reported the job as a failure.
server1 DAILY_INC Failed 2008-01-30 20:53:53
Did anyone find a solution to this ?
 
We are having the same problem on a select group of clients since upgrading our server to TSM 5.4.2.0. We have not actually upgraded the clients yet so I was thinking it could be because most of the clients are still running TSM 5.2 but apparently this is not the case. I'm going to see if these clients have anything in common. Has anyone found a solution?
 
By any chance, are these Win2K3 R2 with SP2?

If they are, search for the fix about TCP Chimney. We had this problem...
 
Well, most are win2003 with SP1, but some are R2, and some are windows 2k servers.

We have Downgraded the client to 5.4.1.6, and it seems they no longer "failes", And for win2k server its TSM Client version 5.3.5C that seems to do the trick.
 
OK, we upgraded our server to 5.4.2.0 a month ago and since then we have had mis-reporting for several clients. NT4.0, SLES Linux, W2K and W2K3. Tried upgrading and downgrading the BA clients, some success with them but still have Linux, W23K and NT 4.0 boxes that are being stubborn.

The 5.4.1.0 client on Windows boxes seems to work best.
The 5.2.3.1 and 5.2.5.0 clients for Linux seem ok.

NT 4.0 you're basically buggered because the latest client is 5.1.7.3 and no real suprise that this won't be getting an update.

We get the mis-reports in TSM Manager 4.3, in the TSM Operational reporting and in a perl script written gui front end provided by our TSM reseller.

It shows a return code of -99 and the local dsmsched.log files all show that the backup completed successfully on all the problem nodes. No errors reported in the act log either so I'm buggered if I can work out where the hell these reporting tools are getting a -99 error code from.

Any divine inspiration out there cos I am going out of my tree!
 
Back
Top