Your right, I am on a Windows 2K3 server and I recently migrated from
version 5.2.1.3 to 5.3.2.0. I'll try out those suggestions.
Mel Dennis
Systems Engineer - IT743
Siemens Power Generation
4400 Alafaya Trail
Orlando, FL 32826
MC Q1-110
Tel: (407) 736-2360
Win: 439-2360
Fax: (407) 736-5069
Email: melburn.dennis AT siemens DOT com
-----Original Message-----
From: ADSM: Dist Stor Manager [mailto:ADSM-L AT VM.MARIST DOT EDU] On Behalf Of
Prather, Wanda
Sent: Monday, November 21, 2005 11:13 AM
To: ADSM-L AT VM.MARIST DOT EDU
Subject: Re: [ADSM-L] Errors when running Space Reclamation
When posting PLEASE INCLUDE YOUR SERVER platform & version.
If you have recently upgraded to TSM 5.3.x, it may be IC47584.
I have a PMR open and am hoping to get a test fix shortly.
While annoying, it appears to be harmless.
Try cleaning up that volume by doing a MOVE DATA instead of a
reclamation.
If that doesn't work, see if it is continually trying to mount the same
output tape.
If so, mark that tape as READONLY until you get past this problem.
In every case, by simply changing the combination of input/output tapes,
I've been able to get past it.
(But then it just pops up in another place a few days later.)
I am TSM 5.2.3.0 on Windows.
Wanda Prather
"I/O, I/O, It's all about I/O" -(me)
-----Original Message-----
From: ADSM: Dist Stor Manager [mailto:ADSM-L AT VM.MARIST DOT EDU] On Behalf Of
Dennis Melburn W IT743
Sent: Monday, November 21, 2005 9:06 AM
To: ADSM-L AT VM.MARIST DOT EDU
Subject: Errors when running Space Reclamation
I have been recieving Space Reclamation Failures on my TSM server lately
and I am not sure why. When I go back to the time of the events, I get
the following ANR9999D log report: (sorry for the length of the report,
but I figured it would be best to include it all)
11/20/2005 15:59:12 ANR8337I LTO volume A00541 mounted in drive
LTODRV13
(mt4.3.1.3). (SESSION: 25342)
11/20/2005 15:59:12 ANR0510I Session 25342 opened input volume
A00541.
(SESSION: 25342)
11/20/2005 16:00:28 ANR9999D afmove.c(5788): ThreadId<43>
Unexpected result
code (45) from ssCopy. (SESSION: 25342)
11/20/2005 16:00:28 ANR9999D ThreadId<43> issued message 9999 from:
(SESSION: 25342)
11/20/2005 16:00:28 (43) Context report (SESSION: 25342)
11/20/2005 16:00:29 (43) Thread SsAuxSinkThread (45) is a child
thread related
to: 43 (SESSION: 25342)
11/20/2005 16:00:29 (45) Generating TM Context Report:
(struct=tmTxnDesc)
(slots=256) (SESSION: 25342)
11/20/2005 16:00:29 (45) *** no transactions found *** (SESSION:
25342)
11/20/2005 16:00:29 (45) Generating Database Transaction Table
Context:
(SESSION: 25342)
11/20/2005 16:00:29 (45) *** no transactions found *** (SESSION:
25342)
11/20/2005 16:00:29 (45) Generating SM Context Report: (SESSION:
25342)
11/20/2005 16:00:29 (45) *** no sessions found *** (SESSION:
25342)
11/20/2005 16:00:29 (45) Generating AS Vol Context Report:
(SESSION: 25342)
11/20/2005 16:00:29 (45) No mounted (or mount in progress)
volumes. (SESSION:
25342)
11/20/2005 16:00:29 (45) Failed attempt #1 to get SSV->mutex
(SESSION: 25342)
11/20/2005 16:00:29 (45) Generating ssSession Context Report:
(SESSION:
25342)
11/20/2005 16:00:29 (45) No storage service sessions active.
(SESSION: 25342)
11/20/2005 16:00:29 (45) Generating ssOpenSeg Context Report:
(SESSION:
25342)
11/20/2005 16:00:29 (45) No storage service segments found.
(SESSION: 25342)
11/20/2005 16:00:29 (45) Generating BF Copy Control Context Report:
(SESSION:
25342)
11/20/2005 16:00:29 (45) No global copy control blocks. (SESSION:
25342)
11/20/2005 16:00:29 (SESSION: 25342)
11/20/2005 16:00:29 (43) Thread SsAuxSrcThread (46) is a child
thread related
to: 43 (SESSION: 25342)
11/20/2005 16:00:29 (46) Generating TM Context Report:
(struct=tmTxnDesc)
(slots=256) (SESSION: 25342)
11/20/2005 16:00:29 (46) *** no transactions found *** (SESSION:
25342)
11/20/2005 16:00:29 (46) Generating Database Transaction Table
Context:
(SESSION: 25342)
11/20/2005 16:00:29 (46) Tsn=0:160675859 --> Valid=1, inRollback=0,
endNTA=0,
State=2, Index=3, LatchCount=0, SavePoint=0,
TotLogRecs=0, TotLogBytes=0, UndoLogRecs=0,
UndoLogBytes=0, LogReserve=0, PageReserve=0,
Elapsed=99
(secs), MinLsn=0.0.0, MaxLsn=0.0.0,
LastLsn=0.0.0,
UndoNextLsn=0.0.0, logWriter=False,
backupTxn=False
(SESSION: 25342)
11/20/2005 16:00:29 (46) Open objects: (SESSION: 25342)
11/20/2005 16:00:29 (46) name ->AF.Damaged<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:29 (46) name ->BF.Aggregate.Attributes<- (sp=0)
(SESSION:
25342)
11/20/2005 16:00:29 (46) name ->AF.Vol.Segments<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:29 (46) name ->Restore.Sessions<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:29 (46) name ->Collocation.Group.Member<-
(sp=0) (SESSION:
25342)
11/20/2005 16:00:29 (46) name ->AF.Vol.Clusters<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:29 (46) name ->AS.Volume.Status<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:29 (46) name ->AF.Segments<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:29 (46) name ->AF.Bitfiles<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:29 (46) name ->AF.Vol.Partial.Bitfiles<- (sp=0)
(SESSION:
25342)
11/20/2005 16:00:29 (46) name ->SS.Volume.Names<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:29 (46) name ->SS.Volume.Ids<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:29 (46) *** no transactions found *** (SESSION:
25342)
11/20/2005 16:00:29 (46) Generating SM Context Report: (SESSION:
25342)
11/20/2005 16:00:29 (46) *** no sessions found *** (SESSION:
25342)
11/20/2005 16:00:29 (46) Generating AS Vol Context Report:
(SESSION: 25342)
11/20/2005 16:00:29 (46) Mounted (or mount in progress) volumes:
(SESSION:
25342)
11/20/2005 16:00:29 (46) Volume A00541(16084) --> SessId=10414,
Server=BACKUP1 Mode=Input, Use=Bitfile,
ClassId=1,
ClassName=LTO2CLASS, IsScratch=True,
VolSeqNum=0,
Pool=ORL-DMNO-TAPE(16), Allocated=False,
NextSeqNum=640,
PosUncertain=True, Open=True,
OpenInProg=False,
OpenFailed= False, MountMode=Read-only,
Reuse=Remove,
IsFirstMount=False, IsEmpty=False,
IsNewScratch=False,
PreemptAccess=False, Waiters=0,
TwoSided=False,
SideSeqNum=-1, status=ACTIVE (SESSION: 25342)
11/20/2005 16:00:29 (46) Failed attempt #1 to get SSV->mutex
(SESSION: 25342)
11/20/2005 16:00:29 (46) Generating ssSession Context Report:
(SESSION:
25342)
11/20/2005 16:00:29 (46) No storage service sessions active.
(SESSION: 25342)
11/20/2005 16:00:29 (46) Generating ssOpenSeg Context Report:
(SESSION:
25342)
11/20/2005 16:00:29 (46) No storage service segments found.
(SESSION: 25342)
11/20/2005 16:00:29 (46) Generating BF Copy Control Context Report:
(SESSION:
25342)
11/20/2005 16:00:29 (46) No global copy control blocks. (SESSION:
25342)
11/20/2005 16:00:29 (SESSION: 25342)
11/20/2005 16:00:29 (43) Thread AgentThread (41) is a grandchild
thread
related to: 45 (SESSION: 25342)
11/20/2005 16:00:30 (41) Generating TM Context Report:
(struct=tmTxnDesc)
(slots=256) (SESSION: 25342)
11/20/2005 16:00:30 (41) *** no transactions found *** (SESSION:
25342)
11/20/2005 16:00:30 (41) Generating Database Transaction Table
Context:
(SESSION: 25342)
11/20/2005 16:00:30 (41) Tsn=0:160675983 --> Valid=1, inRollback=0,
endNTA=0,
State=2, Index=0, LatchCount=0, SavePoint=0,
TotLogRecs=360, TotLogBytes=81512,
UndoLogRecs=350,
UndoLogBytes=80952, LogReserve=0,
PageReserve=0,
Elapsed=11 (secs), MinLsn=1226851.241.3647,
MaxLsn=1226852.20.3872,
LastLsn=1226852.20.3872,
UndoNextLsn=0.0.0, logWriter=False,
backupTxn=False
(SESSION: 25342)
11/20/2005 16:00:30 (41) Open objects: (SESSION: 25342)
11/20/2005 16:00:30 (41) name ->AF.Vol.Clusters<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:30 (41) name ->AF.Clusters<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:30 (41) name ->AF.Vol.Partial.Bitfiles<- (sp=0)
(SESSION:
25342)
11/20/2005 16:00:30 (41) name ->AF.Vol.Segments<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:30 (41) name ->AF.Segments<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:30 (41) name ->BF.Aggregate.Attributes<- (sp=0)
(SESSION:
25342)
11/20/2005 16:00:30 (41) name ->AF.Bitfiles<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:30 (41) name ->AS.Segments<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:30 (41) name ->SS.Pools<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:30 (41) name ->SS.Pool.Ids<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:30 (41) *** no transactions found *** (SESSION:
25342)
11/20/2005 16:00:30 (41) Generating SM Context Report: (SESSION:
25342)
11/20/2005 16:00:30 (41) *** no sessions found *** (SESSION:
25342)
11/20/2005 16:00:30 (41) Generating AS Vol Context Report:
(SESSION: 25342)
11/20/2005 16:00:30 (41) No mounted (or mount in progress)
volumes. (SESSION:
25342)
11/20/2005 16:00:30 (41) Failed attempt #1 to get SSV->mutex
(SESSION: 25342)
11/20/2005 16:00:30 (41) Generating ssSession Context Report:
(SESSION:
25342)
11/20/2005 16:00:30 (41) No storage service sessions active.
(SESSION: 25342)
11/20/2005 16:00:30 (41) Generating ssOpenSeg Context Report:
(SESSION:
25342)
11/20/2005 16:00:30 (41) No storage service segments found.
(SESSION: 25342)
11/20/2005 16:00:30 (41) Generating BF Copy Control Context Report:
(SESSION:
25342)
11/20/2005 16:00:30 (41) No global copy control blocks. (SESSION:
25342)
11/20/2005 16:00:30 (SESSION: 25342)
11/20/2005 16:00:30 (43) Thread AgentThread (47) is a grandchild
thread
related to: 46 (SESSION: 25342)
11/20/2005 16:00:30 (47) Generating TM Context Report:
(struct=tmTxnDesc)
(slots=256) (SESSION: 25342)
11/20/2005 16:00:30 (47) *** no transactions found *** (SESSION:
25342)
11/20/2005 16:00:30 (47) Generating Database Transaction Table
Context:
(SESSION: 25342)
11/20/2005 16:00:30 (47) *** no transactions found *** (SESSION:
25342)
11/20/2005 16:00:30 (47) Generating SM Context Report: (SESSION:
25342)
11/20/2005 16:00:30 (47) *** no sessions found *** (SESSION:
25342)
11/20/2005 16:00:30 (47) Generating AS Vol Context Report:
(SESSION: 25342)
11/20/2005 16:00:30 (47) No mounted (or mount in progress)
volumes. (SESSION:
25342)
11/20/2005 16:00:30 (47) Failed attempt #1 to get SSV->mutex
(SESSION: 25342)
11/20/2005 16:00:30 (47) Generating ssSession Context Report:
(SESSION:
25342)
11/20/2005 16:00:30 (47) No storage service sessions active.
(SESSION: 25342)
11/20/2005 16:00:30 (47) Generating ssOpenSeg Context Report:
(SESSION:
25342)
11/20/2005 16:00:30 (47) No storage service segments found.
(SESSION: 25342)
11/20/2005 16:00:30 (47) Generating BF Copy Control Context Report:
(SESSION:
25342)
11/20/2005 16:00:30 (47) No global copy control blocks. (SESSION:
25342)
11/20/2005 16:00:31 (SESSION: 25342)
11/20/2005 16:00:31 (43) Thread AfReclamationAgent (66) is a parent
thread
related to: 43 (SESSION: 25342)
11/20/2005 16:00:31 (66) Generating TM Context Report:
(struct=tmTxnDesc)
(slots=256) (SESSION: 25342)
11/20/2005 16:00:31 (66) slot -> 14: (SESSION: 25342)
11/20/2005 16:00:31 (66) Tsn=0:160675854, Resurrected=False,
InFlight=True,
Distributed=False (SESSION: 25342)
11/20/2005 16:00:31 (66) Participants=0, summaryVote=ReadOnly
(SESSION:
25342)
11/20/2005 16:00:31 (66) Generating Database Transaction Table
Context:
(SESSION: 25342)
11/20/2005 16:00:31 (66) *** no transactions found *** (SESSION:
25342)
11/20/2005 16:00:31 (66) Generating SM Context Report: (SESSION:
25342)
11/20/2005 16:00:31 (66) *** no sessions found *** (SESSION:
25342)
11/20/2005 16:00:31 (66) Generating AS Vol Context Report:
(SESSION: 25342)
11/20/2005 16:00:31 (66) No mounted (or mount in progress)
volumes. (SESSION:
25342)
11/20/2005 16:00:31 (66) Generating ssSession Context Report:
(SESSION:
25342)
11/20/2005 16:00:31 (66) Storage Service Sessions: (SESSION:
25342)
11/20/2005 16:00:31 (66) Session 10414 --> BufConfig=XLarge,
TransBufSize=262144, SplitBuf=False,
WrCount=32768,
WrBufIsEmpty=False, WrBufIsFull=False,
SourceRc=45,
SinkRc=45, Aux_1Created=True,
Aux_1Begin=False,
Aux_1Idle=True, Aux_1Terminate=False,
Aux_2Created=True,
Aux_2Begin=False, Aux_2Idle=True,
Aux_2Terminate=False
(SESSION: 25342)
11/20/2005 16:00:31 (66) Leased Volumes:(SESSION: 25342)
11/20/2005 16:00:31 (66) A00541(16084)(Access)(SESSION: 25342)
11/20/2005 16:00:31 (SESSION: 25342)
11/20/2005 16:00:31 (66) Excluded VolIds:(SESSION: 25342)
11/20/2005 16:00:31 (66) 16084(SESSION: 25342)
11/20/2005 16:00:31 (SESSION: 25342)
11/20/2005 16:00:31 (66) AS Extension: WrMpClassId=1,
RdMpClassId=1,
ForceRelease=False. (SESSION: 25342)
11/20/2005 16:00:31 (SESSION: 25342)
11/20/2005 16:00:31 (66) Generating ssOpenSeg Context Report:
(SESSION:
25342)
11/20/2005 16:00:31 (66) No storage service segments found.
(SESSION: 25342)
11/20/2005 16:00:31 (66) Generating BF Copy Control Context Report:
(SESSION:
25342)
11/20/2005 16:00:31 (66) No global copy control blocks. (SESSION:
25342)
11/20/2005 16:00:31 (66) procNum=501, status=Volume A00541
(storage pool
ORL-DMNO-TAPE), Moved Files: 0, Moved Bytes:
0,
Unreadable Files: 0, Unreadable Bytes: 0.
Current
Physical File (bytes): 1,350,673 Current input
volume:
A00541. , cancelInProgress=False (SESSION:
25342)
11/20/2005 16:00:31 (66) descr=Space Reclamation, name=SPACE
RECLAMATION,
cancelled=False (SESSION: 25342)
11/20/2005 16:00:31 (SESSION: 25342)
11/20/2005 16:00:31 (43) AfRclmVolumeThread : ANR9999D calling
thread
(SESSION: 25342)
11/20/2005 16:00:31 (43) Generating TM Context Report:
(struct=tmTxnDesc)
(slots=256) (SESSION: 25342)
11/20/2005 16:00:31 (43) slot -> 19: (SESSION: 25342)
11/20/2005 16:00:31 (43) Tsn=0:160675859, Resurrected=False,
InFlight=True,
Distributed=False (SESSION: 25342)
11/20/2005 16:00:31 (43) Participants=1, summaryVote=ReadOnly
(SESSION:
25342)
11/20/2005 16:00:31 Participant DB: voteReceived=False,
ackReceived=False
(SESSION: 25342)
11/20/2005 16:00:31 (43) slot -> 26: (SESSION: 25342)
11/20/2005 16:00:31 (43) Tsn=0:160675866, Resurrected=False,
InFlight=True,
Distributed=False (SESSION: 25342)
11/20/2005 16:00:31 (43) Participants=3, summaryVote=ReadOnly
(SESSION:
25342)
11/20/2005 16:00:31 Participant DB: voteReceived=False,
ackReceived=False
(SESSION: 25342)
11/20/2005 16:00:31 Participant BF: voteReceived=False,
ackReceived=False
(SESSION: 25342)
11/20/2005 16:00:31 Participant SS: voteReceived=False,
ackReceived=False
(SESSION: 25342)
11/20/2005 16:00:31 Locks held by Tsn=0:160675866 : (SESSION:
25342)
11/20/2005 16:00:31 Type=34040, NameSpace=16084,
SummMode=xLock,
Mode=xLock, Key='179.0' (SESSION: 25342)
11/20/2005 16:00:31 (43) Generating Database Transaction Table
Context:
(SESSION: 25342)
11/20/2005 16:00:31 (43) Tsn=0:160674098 --> Valid=1, inRollback=0,
endNTA=0,
State=2, Index=5, LatchCount=0, SavePoint=0,
TotLogRecs=0, TotLogBytes=0, UndoLogRecs=0,
UndoLogBytes=0, LogReserve=0, PageReserve=0,
Elapsed=3623
(secs), MinLsn=0.0.0, MaxLsn=0.0.0,
LastLsn=0.0.0,
UndoNextLsn=0.0.0, logWriter=False,
backupTxn=False
(SESSION: 25342)
11/20/2005 16:00:31 (43) Open objects: (SESSION: 25342)
11/20/2005 16:00:31 (43) name ->Restore.Sessions<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:31 (43) name ->AF.Damaged<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:31 (43) name ->BF.Aggregate.Attributes<- (sp=0)
(SESSION:
25342)
11/20/2005 16:00:31 (43) name ->AF.Vol.Segments<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:31 (43) name ->AS.Volume.Status<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:31 (43) name ->AF.Segments<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:31 (43) name ->AF.Bitfiles<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:31 (43) name ->AF.Vol.Partial.Bitfiles<- (sp=0)
(SESSION:
25342)
11/20/2005 16:00:31 (43) name ->SS.Volume.Names<- (sp=0)
(SESSION: 25342)
11/20/2005 16:00:31 (43) name ->SS.Volume.Ids<- (sp=0) (SESSION:
25342)
11/20/2005 16:00:31 (43) *** no transactions found *** (SESSION:
25342)
11/20/2005 16:00:31 (43) Generating SM Context Report: (SESSION:
25342)
11/20/2005 16:00:31 (43) *** no sessions found *** (SESSION:
25342)
11/20/2005 16:00:31 (43) Generating AS Vol Context Report:
(SESSION: 25342)
11/20/2005 16:00:31 (43) No mounted (or mount in progress)
volumes. (SESSION:
25342)
11/20/2005 16:00:31 (43) Failed attempt #1 to get SSV->mutex
(SESSION: 25342)
11/20/2005 16:00:31 (43) Generating ssSession Context Report:
(SESSION:
25342)
11/20/2005 16:00:31 (43) No storage service sessions active.
(SESSION: 25342)
11/20/2005 16:00:31 (43) Generating ssOpenSeg Context Report:
(SESSION:
25342)
11/20/2005 16:00:31 (43) No storage service segments found.
(SESSION: 25342)
11/20/2005 16:00:31 (43) Generating BF Copy Control Context Report:
(SESSION:
25342)
11/20/2005 16:00:31 (43) No global copy control blocks. (SESSION:
25342)
11/20/2005 16:00:31 (SESSION: 25342)
11/20/2005 16:00:31 (43) End Context report (SESSION: 25342)
11/20/2005 16:00:31 ANR1092E Space reclamation is ended for volume
A00541. An
internal server error was detected. (SESSION:
25342)
11/20/2005 16:00:31 ANR9999D ThreadId<43> issued message 1092 from:
(SESSION: 25342)
11/20/2005 16:00:31 ANR0985I Process 501 for SPACE RECLAMATION
running in the
BACKGROUND completed with completion state
FAILURE at
16:00:31. (SESSION: 25342)
11/20/2005 16:00:31 ANR0514I Session 25342 closed volume A00541.
(SESSION:
25342)
11/20/2005 16:00:31 ANR0408I Session 25352 started for server
TSMLIBMGR
(Windows) (Tcp/Ip) for library sharing.
(SESSION: 25342)
11/20/2005 16:00:31 ANR0409I Session 25352 ended for server
TSMLIBMGR
(Windows). (SESSION: 25342)
11/20/2005 16:00:31 ANR0408I Session 25353 started for server
TSMLIBMGR
(Windows) (Tcp/Ip) for library sharing.
(SESSION: 25342)
11/20/2005 16:00:31 ANR0409I Session 25353 ended for server
TSMLIBMGR
(Windows). (SESSION: 25342)
11/20/2005 16:00:31 ANR0408I Session 25354 started for server
TSMLIBMGR
(Windows) (Tcp/Ip) for library sharing.
(SESSION: 25342)
11/20/2005 16:00:31 ANR0409I Session 25354 ended for server
TSMLIBMGR
(Windows). (SESSION: 25342)
11/20/2005 16:00:31 ANR4936I Reclamation of storage pool
ORL-DMNO-TAPE has
ended. Files reclaimed: 0, Bytes reclaimed: 0,
Files
reconstructed: 0, Unreadable files: 0.
(SESSION: 25342)
11/20/2005 16:05:31 ANR8468I LTO volume A00541 dismounted from
drive LTODRV13
(mt4.3.1.3) in library ADIC-TSM. (SESSION:
25342)
The report is pretty much the same for other failed attempts at Space
Reclamation and it occurs on a daily basis.
|
