I thought that initially aswell, but the rc-50s are prior to the actual
backup. it was rescheduled to run at 10:30, after a false 2 hour start
from 8:30 am.
Those ANS1289W's appear after the client and server are happily talking,
according to the sched.log.
----------------------------------------------------------------------------------------------------
Executing scheduled command now.
18-06-2005 08:30:24
Executing Operating System command or script:
C:\Progra~1\IBM_FAStT\util\flashcopy_recreate_advanced.bat >>
C:\Progra~1\IBM_FAStT\util\log_recreate.txt
18-06-2005 08:32:17 Finished command. Return code is: 0
18-06-2005 08:32:17 Node Name: DATL900IV-TSMTARGET
18-06-2005 08:32:17 Session established with server TSML003A: Windows
18-06-2005 08:32:17 Server Version 5, Release 2, Level 0.0
18-06-2005 08:32:17 Server date/time: 18-06-2005 08:32:18 Last access:
18-06-2005 04:41:24
18-06-2005 08:32:17
Backup Image Function Invoked.
18-06-2005 10:17:01 ANS1228E Sending of object '\\tsml902a\f$' failed
18-06-2005 10:17:01 ANS1017E Session rejected: TCP/IP connection failure
18-06-2005 10:17:01 ANS1813E Image Backup processing of '\\tsml902a\f$'
finished with failures.
18-06-2005 10:17:01 Session established with server TSML003A: Windows
18-06-2005 10:17:02 Server Version 5, Release 2, Level 0.0
18-06-2005 10:17:02 Server date/time: 18-06-2005 10:17:02 Last access:
18-06-2005 10:17:01
18-06-2005 10:17:02 Total number of objects inspected: 1
18-06-2005 10:17:02 Total number of objects backed up: 0
18-06-2005 10:17:02 Total number of objects updated: 0
18-06-2005 10:17:02 Total number of objects rebound: 0
18-06-2005 10:17:02 Total number of objects deleted: 0
18-06-2005 10:17:02 Total number of objects expired: 0
18-06-2005 10:17:02 Total number of objects failed: 1
18-06-2005 10:17:02 Total number of bytes transferred: 245.18 GB
18-06-2005 10:17:02 Data transfer time: 5,954.00 sec
18-06-2005 10:17:02 Network data transfer rate: 43,181.01 KB/sec
18-06-2005 10:17:02 Aggregate data transfer rate: 40,913.08 KB/sec
18-06-2005 10:17:02 Objects compressed by: 0%
18-06-2005 10:17:02 Elapsed processing time: 01:44:44
18-06-2005 10:17:02
Executing Operating System command or script:
C:\Progra~1\IBM_FAStT\util\flashcopy_disable_basic.bat >>
C:\Progra~1\IBM_FAStT\util\log_disable.txt
18-06-2005 10:18:10 Querying server for next scheduled event.
18-06-2005 10:18:10 Node Name: DATL900IV-TSMTARGET
18-06-2005 10:18:10 Session established with server TSML003A: Windows
18-06-2005 10:18:10 Server Version 5, Release 2, Level 0.0
18-06-2005 10:18:10 Server date/time: 18-06-2005 10:18:10 Last access:
18-06-2005 10:18:08
18-06-2005 10:18:10 --- SCHEDULEREC QUERY BEGIN
18-06-2005 10:18:10 --- SCHEDULEREC QUERY END
18-06-2005 10:18:10 Next operation scheduled:
18-06-2005 10:18:10
------------------------------------------------------------
18-06-2005 10:18:10 Schedule Name: FILE_WEEKEND_IMAGE
18-06-2005 10:18:10 Action: Backup Image
18-06-2005 10:18:10 Objects: f:
18-06-2005 10:18:10 Options:
18-06-2005 10:18:10 Server Window Start: 10:30:00 on 18-06-2005
18-06-2005 10:18:10
------------------------------------------------------------
18-06-2005 10:18:10 Command will be executed in 12 minutes.
18-06-2005 10:20:50 Querying server for next scheduled event.
18-06-2005 10:20:50 Node Name: DATL900IV-TSMTARGET
18-06-2005 10:20:50 Session established with server TSML003A: Windows
18-06-2005 10:20:50 Server Version 5, Release 2, Level 0.0
18-06-2005 10:20:50 Server date/time: 18-06-2005 10:20:50 Last access:
18-06-2005 10:20:49
18-06-2005 10:20:50 --- SCHEDULEREC QUERY BEGIN
18-06-2005 10:20:50 --- SCHEDULEREC QUERY END
18-06-2005 10:20:50 Next operation scheduled:
18-06-2005 10:20:50
------------------------------------------------------------
18-06-2005 10:20:50 Schedule Name: FILE_WEEKEND_IMAGE
18-06-2005 10:20:50 Action: Backup Image
18-06-2005 10:20:50 Objects: f:
18-06-2005 10:20:50 Options:
18-06-2005 10:20:50 Server Window Start: 10:22:00 on 18-06-2005
18-06-2005 10:20:50
------------------------------------------------------------
18-06-2005 10:20:50 Command will be executed in 3 minutes.
18-06-2005 10:23:50
Executing scheduled command now.
18-06-2005 10:23:50
Executing Operating System command or script:
C:\Progra~1\IBM_FAStT\util\flashcopy_recreate_advanced.bat >>
C:\Progra~1\IBM_FAStT\util\log_recreate.txt
18-06-2005 10:25:45 Finished command. Return code is: 0
18-06-2005 10:25:45 Node Name: DATL900IV-TSMTARGET
18-06-2005 10:25:45 Session established with server TSML003A: Windows
18-06-2005 10:25:45 Server Version 5, Release 2, Level 0.0
18-06-2005 10:25:45 Server date/time: 18-06-2005 10:25:45 Last access:
18-06-2005 10:20:50
18-06-2005 10:25:45
Backup Image Function Invoked.
18-06-2005 10:37:44 ANS1228E Sending of object '\\tsml902a\f$' failed
18-06-2005 10:37:44 ANS1069E An error occurred while reading data from the
device
18-06-2005 10:37:44 ANS1813E Image Backup processing of '\\tsml902a\f$'
finished with failures.
18-06-2005 10:37:44 Total number of objects inspected: 1
18-06-2005 10:37:44 Total number of objects backed up: 0
18-06-2005 10:37:44 Total number of objects updated: 0
18-06-2005 10:37:44 Total number of objects rebound: 0
18-06-2005 10:37:44 Total number of objects deleted: 0
18-06-2005 10:37:44 Total number of objects expired: 0
18-06-2005 10:37:44 Total number of objects failed: 1
18-06-2005 10:37:44 Total number of bytes transferred: 18.71 GB
18-06-2005 10:37:44 Data transfer time: 542.00 sec
18-06-2005 10:37:44 Network data transfer rate: 36,208.03 KB/sec
18-06-2005 10:37:44 Aggregate data transfer rate: 27,293.93 KB/sec
18-06-2005 10:37:44 Objects compressed by: 0%
18-06-2005 10:37:44 Elapsed processing time: 00:11:59
18-06-2005 10:37:44
Executing Operating System command or script:
C:\Progra~1\IBM_FAStT\util\flashcopy_disable_basic.bat >>
C:\Progra~1\IBM_FAStT\util\log_disable.txt
18-06-2005 10:37:44 Finished command. Return code is: 1
18-06-2005 10:37:44 ANS1903W The POSTCHEDULECMD command failed.
18-06-2005 10:37:44 ANS1512E Scheduled event 'FILE_WEEKEND_IMAGE' failed.
Return code = 12.
18-06-2005 10:37:44 Sending results for scheduled event
'FILE_WEEKEND_IMAGE'.
18-06-2005 10:37:44 Results sent to server for scheduled event
'FILE_WEEKEND_IMAGE'.
---------------------------------------------------------------------------------------
The Backup Image process was started twice having been cancelled the first
time. Would that really cause bad sector errors?
Cheers Mark,
Matthew
"Stapleton, Mark" <mark.stapleton AT BERBEE DOT COM>
Sent by: "ADSM: Dist Stor Manager" <ADSM-L AT VM.MARIST DOT EDU>
20/06/2005 15:39
Please respond to
"ADSM: Dist Stor Manager" <ADSM-L AT VM.MARIST DOT EDU>
To
ADSM-L AT VM.MARIST DOT EDU
cc
Subject
Re: [ADSM-L] ANS1289W - bad areas on disk
From: ADSM: Dist Stor Manager [mailto:ADSM-L AT VM.MARIST DOT EDU] On
Behalf Of Matthew Large
>We had an image backup failure over the weekend. The schedule
>started as
>it normally does at 08:30am, but it was stopped a few hours
>later (he had
>expected it to use two drives), so he updated the schedule to
>start a few
>minutes later. it started again, and failed with these messages in the
>dsmerror.log
>
>It's the ANS1289W's that I'm interested in.
>
>18-06-2005 10:16:47 sessSendVerb: Error sending Verb, rc: -50
>18-06-2005 10:16:47 sessSendVerb: Error sending Verb, rc: -50
>18-06-2005 10:16:47 ANS1017E (RC-50) Session rejected: TCP/IP
>connection
>failure
>18-06-2005 10:16:47 ANS1424W Retrying failed image operation for volume
>\\tsml902a\f$.
>18-06-2005 10:16:59 sessSendVerb: Error sending Verb, rc: -50
>18-06-2005 10:16:59 sessSendVerb: Error sending Verb, rc: -50
>18-06-2005 10:17:01 ANS1228E Sending of object '\\tsml902a\f$' failed
>18-06-2005 10:17:01 ANS1017E Session rejected: TCP/IP
>connection failure
>
>18-06-2005 10:17:01 ANS1813E Image Backup processing of '\\tsml902a\f$'
>finished with failures.
>
>18-06-2005 10:37:28 ANS1289W Bad areas on '\\tsml902a\f$'
>between sectors
>0:8b0bea8 and 0:8b0c0a7
>[snip]
>18-06-2005 10:37:42 ANS2026W Bad sectors were detected on the volume
>'\\tsml902a\f$'.
>18-06-2005 10:37:42 ANS1425W Retry of failed image operation for volume
>\\tsml902a\f$ is not possible due to severe error.
>18-06-2005 10:37:44 ANS1228E Sending of object '\\tsml902a\f$' failed
>18-06-2005 10:37:44 ANS1069E An error occurred while reading
>data from the device
>
>This is a 2TB disk and so far I've been unable to convince the
>sysadmins
>that they should run a some kind of disk check before trying to run the
>backup again.
Making an educated WAG here, but I'd say that the drop in communication
(rc: -50) between the client and server is more likely the source of
your problem, rather than bad disk sectors. Image backups are very
sensitive to interruptions in the data stream. Try the image backup
again.
--
Mark Stapleton (stapleton AT berbee DOT com)
IBM Certified Advanced Deployment Professional
Tivoli Storage Management Solutions 2005
IBM Certified Advanced Technical Expert (CATE) AIX
Office 262.521.5627
Aviva plc
Registered Office: St. Helen's, 1 Undershaft, London EC3P 3DQ
Registered in England Number 02468686
www.aviva.com
This message and any attachments are confidential.
If you are not the intended recipient, please telephone
or e-mail the sender and delete this message and any
attachment from your system. Also, if you are not the
intended recipient you must not copy this message or
attachment or disclose the contents to any other person.
|
