IC92089: VOLHISTORY CONTAINS VOLUME ENTRIES FOR FAILED DATABASE BACKUP.

APAR status

• Closed as program error.

Error description

• On Tivoli Storage Manager server 6.3, volume entry may be added
  even when "backup db" ended with failure.
  This is unexpected behavior because this volume history entry is
  not valid and it may be used for "restore db" operation.
  Also, customer may not notice the bad volume history entry.
  They may delete previous valid entries and lose valid volume
  history information for "restore db" operation.
  
  
  Here is an example for the result of "query actlog".
  It can be seen that database backup completed with a completion
  state of FAILURE.
  (Example for the result of "backup db" command)
  ------------------------------
  MM/dd/yyyy HH:mm:SS ANR2017I Administrator ADMIN issued command:
  BACKUP DB type=full devc=dbbackup wait=yes (SESSION: 1)
  MM/dd/yyyy HH:mm:SS ANR8340I FILE volume
  /mnt/dbbackup/67304709.DBV mounted. (SESSION: 1)
  MM/dd/yyyy HH:mm:SS ANR0511I Session 1 opened output volume
  /mnt/dbbackup/67304709.DBV. (SESSION: 1)
  MM/dd/yyyy HH:mm:SS ANR1360I Output volume
  /mnt/dbbackup/67304709.DBV opened (sequence number 1). (SESSION:
  1)
  MM/dd/yyyy HH:mm:SS ANR0984I Process 5 for Database Backup
  started in the FOREGROUND at 12:25:31 PM. (SESSION: 1, PROCESS:
  5)
  MM/dd/yyyy HH:mm:SS ANR4559I Backup DB is in progress. (SESSION:
  1, PROCESS: 5)
  MM/dd/yyyy HH:mm:SS ANR2280I Full database backup started as
  process 5. (SESSION: 1, PROCESS: 5)
  MM/dd/yyyy HH:mm:SS ANR4626I Database backup will use 1 streams
  for processing with the number originally requested 1. (SESSION:
  1, PROCESS: 5)
  MM/dd/yyyy HH:mm:SS ANR8341I End-of-volume reached for FILE
  volume /mnt/dbbackup/67304709.DBV. (SESSION: 1)
  MM/dd/yyyy HH:mm:SS ANR8504E A failure occurred in flushing data
  to volume /mnt/dbbackup/67304709.DBV. (SESSION: 1)
  MM/dd/yyyy HH:mm:SS ANR8785E Out-of-space in file system for
  FILE volume /mnt/dbbackup/67304709.DBV. (SESSION: 1)
  MM/dd/yyyy HH:mm:SS ANR4573E Database backup terminated -
  excessive write errors encountered. (SESSION: 1, PROCESS: 5)
  MM/dd/yyyy HH:mm:SS ANR0985I Process 5 for Database Backup
  running in the FOREGROUND completed with completion state
  FAILURE at 12:26:16 PM. (SESSION: 1, PROCESS: 5)
  MM/dd/yyyy HH:mm:SS ANR1893E Process 5 for Database Backup
  completed with a completion state of FAILURE. (SESSION: 1,
  PROCESS: 5)
  ------------------------------
  
  
  Even though "backup db" failed, volume entry is added into
  volhistory.
  (Example for the result of "query volhistory" command)
  ------------------------------
  Date/Time: MM/dd/yyyy HH:mm:SS
  Volume Type: BACKUPFULL
  Backup Series: 17
  Backup Operation: 0
  Volume Seq: 10,001
  Device Class: DBBACKUP
  Volume Name: /mnt/dbbackup/67304709.DBV
  ------------------------------
  
  
  Tivoli Storage Manager Versions Affected: TSM 6.3 for all
  platform.
  
  
  Customer/L2 Diagnostics (If Applicable)
  When collecting Tivoli Storage Manager server trace with ICBACK
  ICVOLHST, the following records can be seen.
  It shows that a thread judged that db2Backup ended successfully
  and added an entry into volhist,
  on the other hands, the other thread judged that db backup
  failed for write error.
  
  (Example for result of Tivoli Storage Manager server trace)
  ------------------------------
  HH:mm:SS.sss [492][rdbicbck.c][2024][DoDB2BackupThread]:The
  db2Backup return code is 0
  HH:mm:SS.sss [491][rdbicbck.c][629][RdbDoBackup]:The
  DB2BackupThread return code is 0
  HH:mm:SS.sss [491][rdbicbck.c][648][RdbDoBackup]:The backup DB
  is successful
  HH:mm:SS.sss [491][rdbicbck.c][693][RdbDoBackup]:Backup
  timestamp from DB2 20130430155149.
  HH:mm:SS.sss [491][rdbicbck.c][752][RdbDoBackup]:doVolHist=True
  after evaluation of stream vol lists.
  HH:mm:SS.sss [491][icvolhst.c][9571][IcDoVolHist]:The backup DB
  timestamp is 20130430155149 from DB2
  ...
  HH:mm:SS.sss [491][icvolhst.c][9602][IcDoVolHist]:Updating
  volume history using seriesId=17, opId=0 for database backup
  operation 1.
  HH:mm:SS.sss
  [491][rdbicut.c][416][RdbIcUpdateVolumeHistory]:Handling
  dbbackup stream entries for volHist with RC 0 so far.
  HH:mm:SS.sss
  [491][rdbicut.c][433][RdbIcUpdateVolumeHistory]:DBBackup stream
  1, adding entry for volume /mnt/dbbackup/67304709.DBV.
  HH:mm:SS.sss [491][icvolhst.c][5839][IcvhAddVolume]:
  volName=/mnt/dbbackup/67304709.DBV, type=7,
  volumeDate=04-30-2013 15:51:49 (local), 1367304709 (GMT)
  ...
  HH:mm:SS.sss
  [64][icvolhst.c][7560][IcRefreshHistoryThread]:Current volume
  history file volhist.dat and fullPathNeeded is 0.
  HH:mm:SS.sss
  [64][icvolhst.c][7580][IcRefreshHistoryThread]:Created a shadow
  copy of volume hitory file volhist.dat.20130430155252
  HH:mm:SS.sss
  [64][icvolhst.c][3687][icWriteVolumeHistory]:filename=volhist.da
  t.20130430155252
  ...
  HH:mm:SS.sss [491][icback.c][1300][IcBackupThread]:Returned from
  RdbDoBackup with rc 0.
  HH:mm:SS.sss [491][icback.c][1307][IcBackupThread]:We had a
  write error to a backup vol. rc 3017
  HH:mm:SS.sss [491][icback.c][1313][IcBackupThread]:DB Backup
  failed, rc=3017
  ...
  HH:mm:SS.sss [491][output.c][7271][PutConsoleMsg]:ANR4573E
  Database backup terminated - excessive write errors
  encountered.~
  ------------------------------
  
  
  Initial Impact: Low
  
  
  Additional Keywords: zz63 92384 volhist backup db entry
  

Local fix

Problem summary

• ****************************************************************
  * USERS AFFECTED: All Tivoli Storage Manager server users.     *
  ****************************************************************
  * PROBLEM DESCRIPTION: See error description.                  *
  ****************************************************************
  * RECOMMENDATION: Apply fixing level when available. This      *
  *                 problem is currently projected to be fixed   *
  *                 in level 6.3.4. Note that this is            *
  *                 subject to change at the discretion of IBM.  *
  ****************************************************************
  *
  

Problem conclusion

• This problem was fixed.
  

Temporary fix

Comments

APAR Information

• 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

• R63A PSY

     UP

• R63H PSY

     UP

• R63L PSY

     UP

• R63S PSY

     UP

• R63W PSY

     UP