IT14926: ANS2330E ON UNFREEZE OF VSS WRITERS BECAUSE OF 10 SECOND TIMEOUTEXCEEDED

IBM Spectrum Protectâ„¢ Client 7.1.6 Downloads and READMEs

APAR status

• Closed as program error.

Error description

• VMware guest backups with application protection for Microsoft
  Exchange or Microsoft SQL servers may fail with :
  ANS2330E Failed to unfreeze the VSS writers because the
  snapshot time exceeded the 10 second timeout limitation.
  
  Tivoli Storage Manager Versions Affected:
  Tivoli Storage Manager Client 6.4.x and 7.1.x on Windows
  
  Customer/L2 Diagnostics (If Applicable)
  
  The following example for a guest hosting a Microsoft SQL
  server will be seen when this situation is encountered.
  Entries for a Microsoft Exchange server will be different for
  the purely Exchange processes but similar for the VSS messages.
  
  In the client trace :
  
  <timestamp>:...Freezing writers...
  <timestamp>:...Freezing exited, rc = 0
  <timestamp>:...Writers are frozen, ready to take a snapshot.
  <timestamp>:...Taking snapshot 'TSM-VM Snapshot <timestamp>'
  <timestamp>:...Thawing writers...
  <timestamp>:...Thaw exited, rc2 = 6512
  <timestamp>:...Done in acm section, rc = 6584
  
  In the application event log, we see the VSS timeout error :
  
  Information 08.04.2016 10:44:08 MSSQLSERVER 3197
      Server  I/O is frozen on database msdb. No user action is
  required. However, if I/O is not resumed promptly, you could
  cancel the backup
  Error   08.04.2016 10:44:08 VSS 12298   None
      Volume Shadow Copy Service error: The I/O writes cannot be
  held during the shadow copy creation period on volume
  \\?\Volume {<volume id>}\. The volume index in the shadow copy
  set is 0.
      Error details:
         Open[0x00000000, The operation completed successfully.],
         Flush[0x00000000, The operation completed successfully.],
         Release[0x80042314, The shadow copy provider timed out
  while
                             holding writes to the volume being
  shadow
                             copied. This is probably due to
  excessive
                             activity on the volume by an
  application or a
                             system service. Try again later when
  activity
                             on the volume is reduced.],
         OnRun[0x00000000, The operation completed successfully.].
      Operation:
         Executing Asynchronous Operation
      Context:
         Current State: DoSnapshotSet
  Information <timestamp> MSSQLSERVER 3198
      Server  I/O was resumed on database msdb. No user action is
  required
  Error   08.04.2016 10:44:08 SQLVDI  1   None    SQLVDI:
  Loc=SignalAbort.
      Desc=Client initiates abort. ErrorCode=(0). Process=1428.
      Thread=6584. Client. Instance=. VD=Global\
      {<device ID>}2_SQLVDIMemoryName_0.
  Error   08.04.2016 10:44:08 MSSQLSERVER 3041    Backup
      BACKUP failed to complete the command BACKUP DATABASE msdb.
  Check
      the backup application log for detailed messages.
  Error   08.04.2016 10:44:08 MSSQLSERVER 18210   Server
      BackupVirtualDeviceFile::SendFileInfoBegin:  failure on
  backup
      device '{<device ID>}2'. Operating system
      error 995(The I/O operation has been aborted because of
  either a
      thread exit or an application request.).
  Error   08.04.2016 10:44:08 SQLWRITER   24583   None
      Sqllib error: OLEDB Error encountered calling
  ICommandText::Execute.
      hr = 0x80040e14. SQLSTATE: 42000, Native Error: 3013
        Error state: 1, Severity: 16
        Source: Microsoft SQL Server Native Client 11.0
        Error message: BACKUP DATABASE is terminating abnormally.
        SQLSTATE: 42000, Native Error: 3271
        Error state: 1, Severity: 16
        Source: Microsoft SQL Server Native Client 11.0
       Error message: A nonrecoverable I/O error occurred on file
        "{<device ID>}2:" 995(The I/O operation
        has been aborted because of either a thread exit or an
  application
        request.).
        SQLSTATE: 01000, Native Error: 4035
        Error state: 1, Severity: 0
        Source: Microsoft SQL Server Native Client 11.0
        Error message: Processed 0 pages for database 'msdb',
  file
        'MSDBData' on file 1.
  
  in the system event log, the corresponding Virtual Disk service
  errors on disks where the databases and logs are located will
  show the 10 second timespan and will look like :
  
  Information 08.04.2016 10:44:07 Service Control Manager 7036
  None
        The XR_VSS service entered the running state.
  Information 08.04.2016 10:44:08 Service Control Manager 7036
  None
        The COM+ System Application service entered the stopped
  state.
  
  ==> we see here 11 second before the failure
  
  Error   08.04.2016 10:44:19 volsnap 8   None
        The flush and hold writes operation on volume <X>: timed
  out while waiting for a release writes command.
  
  Initial Impact: High
  
  Additional Keywords: spectrum protect freeze thaw vss timeout
  tdp4ve tsm4ve
  

Local fix

Problem summary

• ****************************************************************
  * USERS AFFECTED:                                              *
  * Tivoli Storage Manager for Virtual Environments Data         *
  * Protection for VMware versions 7.1 and 6.4 running on all    *
  * Microsoft Windows x64 and Linux x86_64 platforms             *
  ****************************************************************
  * PROBLEM DESCRIPTION:                                         *
  * See ERROR DESCRIPTION                                        *
  ****************************************************************
  * RECOMMENDATION:                                              *
  * This issue is projected to be fixed in the Tivoli Storage    *
  * Manager Client on Windows x64 and Linux x86_64  in level     *
  * 7.1.6                                                        *
  * Note 1: The Tivoli Storage Manager (TSM) Client is a         *
  * prerequisite to using the Data Protection for VMware. In     *
  * Data Protection for VMware environments, the TSM Client is   *
  * also known as the data mover.                                *
  *  Note 2: The fix for this APAR addresses one possible cause. *
  * It is possible that after applying the fix, the APAR         *
  * symptoms can still occur. APAR IT15552 is the follow-on APAR *
  * to address the other known underlying cause.                 *
  * Note 3: This is subject to change at the discretion of IBM.  *
  ****************************************************************
  

Problem conclusion

• Application protection unfreeze operation has been enhanced to
  avoid 10 seconds timeout. However as stated above, this is a
  partial fix only. APAR IT15552 is the follow-on APAR to address
  the other known underlying cause.
  

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:

Modules/Macros

• dsmagent
  

Fix information

• Fixed component name

  TSM CLIENT

• Fixed component ID

  5698ISMCL

Applicable component levels

• R71W PSY

     UP

• R71L PSY

     UP

• R64W PSY

     UP

• R64L PSY

     UP