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

Errors when running Space Reclamation

2005-11-21 09:07:17
Subject: Errors when running Space Reclamation
From: Dennis Melburn W IT743 <melburn.dennis AT SIEMENS DOT COM>
To: ADSM-L AT VM.MARIST DOT EDU
Date: Mon, 21 Nov 2005 09:05:35 -0500 
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.
[More with this subject...]
<Prev in Thread] Current Thread [Next in Thread>
Previous by Date:  Re: Migrate TSM Server 4.2.4 on AIX 4.3.3 to 5.3 on Linux Howto (retry), Allen S. Rout
Next by Date:  Re: 5.1.6.2 to 5.2 Upgrade - How to, Allen S. Rout
Previous by Thread:  Migrate TSM Server 4.2.4 on AIX 4.3.3 to 5.3 on Linux Howto (retry), Christoph Martin
Next by Thread:  Re: Errors when running Space Reclamation, Prather, Wanda
Indexes:  [Date] [Thread] [Top] [All Lists]