Direct links to fixes
8.1.15.100-IBM-SPSRV-WindowsX64
8.1.15.100-IBM-SPSRV-Linuxx86_64
8.1.15.100-IBM-SPSRV-Linuxs390x
8.1.15.100-IBM-SPSRV-Linuxppc64le
8.1.15.100-IBM-SPSRV-AIX
8.1.16.000-IBM-SPCMS-WindowsX64
8.1.16.000-IBM-SPCMS-WindowsI32
8.1.16.000-IBM-SPCMS-Linuxx86_64
8.1.16.000-IBM-SPOC-WindowsX64
8.1.16.000-IBM-SPOC-Linuxx86_64
8.1.16.000-IBM-SPOC-Linuxs390x
8.1.16.000-IBM-SPOC-LinuxPPC64le
8.1.16.000-IBM-SPOC-AIX
8.1.16.000-IBM-SPSRV-WindowsX64
8.1.16.000-IBM-SPSRV-Linuxx86_64
8.1.16.000-IBM-SPSRV-Linuxs390x
8.1.16.000-IBM-SPSRV-Linuxppc64le
8.1.16.000-IBM-SPSRV-AIX
8.1.14.200-IBM-SPSRV-WindowsX64
8.1.14.200-IBM-SPSRV-Linuxx86_64
8.1.14.200-IBM-SPSRV-Linuxs390x
8.1.14.200-IBM-SPSRV-Linuxppc64le
8.1.14.200-IBM-SPSRV-AIX
APAR status
Closed as program error.
Error description
SPACE RECLAMATION or MOVE DATA process on a copy pool does not show any progress in data movement. If this reclamation process is cancelled, the reclamation or move data process might stay in status cancelled for hours/days. A side effect of the initial issue can be, that the reclamation thread is pinning the activelog till the process is ended. The IBM Spectrum Protect server actlog might show: 07/20/21 00:29:52 ANR1040I Space reclamation started for volume aaaa, storage pool >stgpoolname< (process number 10622). ==> no progress in data movement 07/20/21 09:46:34 ANR2017I Administrator yyyy issued command: CANCEL PROCESS 10622 07/20/21 09:46:34 ANR0940I Cancel request accepted for process 10622.) ==> long running cancel of the reclamation process 07/21/21 04:54:07 ANR1080W Space reclamation is ended for volume aaaa. The process is cancelled. QUERY PROCESS does not show data movement for example: 07/20/21 00:40:00 10,622 Space Reclamation Volume aaaa (storage pool >stgpoolname<), Moved Files: 8559, Moved Bytes: 20,643 MB, Deduplicated Bytes: 0 bytes, Unreadable Files: 0, Unreadable Bytes: 0 bytes. Current Physical File (bytes): 12,198 MB Current input volume: aaaa. Current output volume(s): bbbb. 07/20/21 09:40:00 10,622 Space Reclamation Volume aaaa (storage pool xxx), Moved Files: 8559, Moved Bytes: 20,643 MB, Deduplicated Bytes: 0 bytes, Unreadable Files: 0, Unreadable Bytes: 0 bytes. Current Physical File (bytes): 12,198 MB Current input volume: aaaa. Current output volume(s): bbbb. From the servermon output *20min-show.txt shows the AgentThread is spending most of the time in ?Tape Locate? Thread 5035708 AgentThread parent=5035667 2021-07-19T02:44:32.948-->2021-07-19T03:04:15.399 SESSION:3383445,PROCESS_NUMBER:10622,PROCESS_DESC:SPACE RECLAMATION,DEVICE:LTOLIB-VZ-122 (/dev/rmtVL3122_f6) Operation Count Tottime Avgtime Mintime Maxtime InstTput Total KB --------------------------------------------------------------- ------------- Tape Read 252 18.247 0.072 0.000 0.115 3535.3 64512 Tape Locate 178 1163.747 6.538 0.014 11.944 ?==== Thread Wait 473 0.048 0.000 0.000 0.001 Unknown 0.406 --------------------------------------------------------------- ------------- Total 1182.451 54.6 64512 A IBM Spectrum Protect Server trace with traceflag PVR might show forward and backward positioning for example: [pvrntp.c][2799][NtpPos]:Positioning NTP volume aaaa to block 28666465, offset 48. [pvrntp.c][2799][NtpPos]:Positioning NTP volume aaaa to block 28666609, offset 48. [pvrntp.c][2799][NtpPos]:Positioning NTP volume aaaa to block 28666465, offset 48. ==> backward [pvrntp.c][2799][NtpPos]:Positioning NTP volume aaaa to block 28666609, offset 48. [pvrntp.c][2799][NtpPos]:Positioning NTP volume aaaa to block 28666465, offset 48. ==> backward [pvrntp.c][2799][NtpPos]:Positioning NTP volume aaaa to block 28666847, offset 48. [pvrntp.c][2799][NtpPos]:Positioning NTP volume aaaa to block 28666465, offset 48. ==>backward [pvrntp.c][2799][NtpPos]:Positioning NTP volume aaaa to block 28666610, offset 48. [pvrntp.c][2799][NtpPos]:Positioning NTP volume aaaa to block 28666465, offset 48. ==> backward [pvrntp.c][2799][NtpPos]:Positioning NTP volume aaaa to block 28666849, offset 48. The activelog pin situation can be seen in the servermon *db2.txt output 20210719T0011-00000002-db2.txt:Appl id holding the oldest transaction = 8322 .. 20210719T1951-00000120-db2.txt:Appl id holding the oldest transaction = 8322 where the *10min-show.txt output shows that the application handle belongs to the reclamation process: SHOW TXNTABLE Tsn=0:1075530252, Resurrected=False, InFlight=True, Distributed=False, Persistent=True, Addr 20be470e0 Start ThreadId=5035608, Timestamp=07/18/21 19:29:52, Creator=afmove.c(7866) Last known in use by ThreadId=5035608 Participants=3, summaryVote=ReadOnly EndInFlight False, endThreadId 0, tmidx 0, processBatchCount 0, mustAbort False. Participant DB: voteReceived=False, ackReceived=False DB: Txn 23005a5a0, ReadOnly(NO), connP=20bd6c520, applHandle=8322, openTbls=4: SHOW THREADS Thread 5035608, Parent 2741: AfRclmVolumeThread, Storage 18922208, AllocCnt 330 HighWaterAmt 18922208 tid=1b58, ptid=4c0b5, det=1, zomb=0, join=0, result=0, sess=0, procToken=10622, sessToken=3383404 Stack trace: 0x09000000005d0200 _cond_wait_global 0x09000000005d0e88 _cond_wait 0x09000000005d182c pthread_cond_wait 0x000000010000b2b4 pkWaitConditionTracked 0x0000000100e3ea04 IPRA.$WaitRdBufFull 0x0000000100e2c6e8 IPRA.$RtrvFramed 0x0000000100e2a4b0 ssRtrv 0x0000000100ebf22c ssReconstruct 0x0000000100e69020 AfReconstruct 0x0000000100c386bc BfReconstruct 0x0000000100efabe4 IPRA.$MoveBatch 0x0000000100ef1efc IPRA.$MoveVolume 0x0000000100ef06b4 AfMoveVolume 0x00000001010a4770 AfRclmOnsiteVols 0x00000001010a2600 AfRclmVolumeThread 0x0000000100011530 StartThread Awaiting cond sessP->rdBufFullCond (0x119acaf70), using mutex sessP->mutex (0x1d434b180), at sstrans.c(11699) Thread context: SESSION: 3383405 THREAD_TYPE: PROCESS PROCESS_DESC: SPACE RECLAMATION PROCESS_NUMBER: 10622 IBM Spectrum Protect versions Affected: IBM Spectrum Protect Version 8.1.10.000 and above on all supported platforms Additional Keywords: TS006246228 reclaim copy move data hang wait activelog pin
Local fix
MOVE DATA <volumename> reconstruct=NO
Problem summary
**************************************************************** * USERS AFFECTED: * * All IBM Spectrum Protect server users. * * * **************************************************************** * PROBLEM DESCRIPTION: * * See error description. * * * **************************************************************** * RECOMMENDATION: * * Apply fixing level when available. * * This problem is currently projected to be fixed in levels * * 8.1.14.200, 8.1.15.100, and 8.1.16. * * Note that this is subject to change at the discretion of * * IBM. * ****************************************************************
Problem conclusion
This problem was fixed. Affected platforms for reported release: AIX, Linux, and Windows. Platforms fixed: AIX, Linux, and Windows.
Temporary fix
Comments
APAR Information
APAR number
IT41125
Reported component name
TSM SERVER
Reported component ID
5698ISMSV
Reported release
81A
Status
CLOSED PER
PE
NoPE
HIPER
NoHIPER
Special Attention
NoSpecatt / Xsystem
Submitted date
2022-06-03
Closed date
2022-06-20
Last modified date
2022-06-20
APAR is sysrouted FROM one or more of the following:
APAR is sysrouted TO one or more of the following:
Fix information
Fixed component name
TSM SERVER
Fixed component ID
5698ISMSV
Applicable component levels
[{"Business Unit":{"code":"BU058","label":"IBM Infrastructure w\/TPS"},"Product":{"code":"SSGSG7","label":"Tivoli Storage Manager"},"Platform":[{"code":"PF025","label":"Platform Independent"}],"Version":"81A","Line of Business":{"code":"LOB26","label":"Storage"}}]
Document Information
Modified date:
01 November 2022