IT15552: VM BACKUP WITH APPLICATION PROTECTION VSS UNFREEZE FAILURE DUE TO 10 SECONDS FLUSH AND HOLD TIMEOUT.

Download Information: Version 8.1.0 IBM Spectrum Protectâ„¢ for Virtual Environments

APAR status

• Closed as fixed if next.

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.
  
  Note: This APAR is a continuation of APAR IT14926.
  IT14926 corrected one underlying cause.
  This APAR is intended to address the other known
  underlying cause.
  
  Tivoli Storage Manager Versions Affected:
  Tivoli Storage Manager Client 6.4.x and 7.1.x on Windows
  
  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&#221;0x00000000, The operation completed successfully.&#168;,
         Flush&#221;0x00000000, The operation completed successfully.&#168;,
         Release&#221;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.&#168;,
         OnRun&#221;0x00000000, The operation completed successfully.&#168;.
      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.
  

Local fix

Problem summary

• ****************************************************************
  * USERS AFFECTED:                                              *
  * Tivoli Storage Manager for Virtual Environments Data         *
  * Protection for VMware versions 7.1 running on Microsoft      *
  * Windows x64 platform using Application Protection            *
  ****************************************************************
  * PROBLEM DESCRIPTION:                                         *
  * See Error Description                                        *
  ****************************************************************
  * RECOMMENDATION:                                              *
  ****************************************************************
  

Problem conclusion

Temporary fix

Comments

• If there is a next release of IBM Spectrum Protect after 7.1,
  this APAR will be fixed in that next release.
  

APAR Information

• APAR is sysrouted FROM one or more of the following:

• APAR is sysrouted TO one or more of the following:

Modules/Macros

• PrxyClt  PrxySrv
  

Fix information

• Fixed component name

  TSM FOR VE DP V

• Fixed component ID

  5725TVEVM

Applicable component levels

• R71W PSN

     UP