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.
|