vStorage restore to a thin provisioned disk using SAN transport mode may fail with "Virtual machine restore: file write failed"

Article:TECH144235  |  Created: 2010-11-15  |  Updated: 2013-04-02  |  Article URL http://www.symantec.com/docs/TECH144235
Article Type
Technical Solution



Issue



When restoring a thin provisioned disk from one datastore to another, the restore may fail if the blocks sizes are of different sizes.


Error



Job details:

11/11/2010 9:59:03 AM - begin reading
11/11/2010 1:12:48 PM - end reading; read time: 03:13:45
11/11/2010 1:12:50 PM - Critical bpbrm(pid=2584) from client VMCLIENT02.SYMANTEC.COM: FTL - Virtual machine restore: file write failed  
...
...
11/11/2010 1:12:51 PM - Critical bpbrm(pid=2584) from client VMCLIENT02.SYMANTEC.COM: FTL - Virtual machine restore: file write failed  
11/11/2010 1:12:58 PM - Error bpbrm(pid=2584) client restore EXIT STATUS 185: tar did not find all the files to be restored
11/11/2010 1:14:00 PM - restored image vmclient02_1289030391 - (the restore failed to recover the requested files(5)); restore time 03:15:29
11/11/2010 1:14:01 PM - end Restore; elapsed time: 03:15:31
the restore failed to recover the requested files(5)
tar:
2:50:56.409 PM: [5276.5852] <4> tar_restore_vxms::get_vix_restore_file: Positioned restore file to ['0'] '<vix>[1_SAN_DS] vmclient02_Restore5/scsi0-0-vmclient02_Restore5.vmdk'
2:50:56.737 PM: [5276.1300] <4> tar_base::keepaliveThread: INF - sending keepalive
2:51:01.534 PM: [5276.5852] <16> tar_restore_vxms::errorHandler: VXMS MESSAGE - severity 90, message 1: fiml_write_vix_file pathname = <vix>[1_SAN_DS] vmclient02_Restore5/scsi0-0-vmclient02_Restore5.vmdk, message 2 = vfm_write failed: err = 11
2:51:01.534 PM: [5276.5852] <16> tar_restore_vxms::errorHandler: VXMS MESSAGE - severity 90, message 1: fiml_write_file pathname = <vix>[1_SAN_DS] vmclient02_Restore5/scsi0-0-vmclient02_Restore5.vmdk, message 2 = fiml_write_vix_file failed stat = 11 
2:51:01.534 PM: [5276.5852] <16> tar_restore_vxms::writeData: fiml_write_file failed error = 11
2:51:01.534 PM: [5276.5852] <4> tar_base::V_vTarMsgW: INF - tar message received from tar_restore_vxms::writeData
2:51:01.534 PM: [5276.5852] <2> tar_base::V_vTarMsgW: FTL - Virtual machine restore: file write failed

VxMS:
Begin: vfm_write [10/15/10 14:51:03]
 Input Parameters:
 nreq=1
  [ Obj ] (0x00EABD18)
    vfm_obj_t { 
      obj_name = 0x0797AE70
      obj_altname = 0x00000000
      obj_orig_name = [1_SAN_DS] vmclient02_Restore5/scsi0-0-vmclient02_Restore5.vmdk
      obj_print_name = [1_SAN_DS] vmclient02_Restore5/scsi0-0-vmclient02_Restore5.vmdk
      obj_configid = 0x00EABD68
      obj_plugin = 0x00ED6980
      obj_libpriv = 0x07953998
      obj_pgnpriv = 0x00EABD08
    }
  [ I/O Req ]
    vfm_io_req_t { 
      io_offset = 26856612352
      io_reqlen = 65536
      io_bufp = 0x07A00D88
      io_bytes_trans = 0
      io_bytes_req = 0
      io_error = 0
    }
       10/15/2010 18:51:03.0097 [TID 0x000016dc]: VixFile::write:h:\701\src\vxms\plugin\common\map\vix\VixFile.h:213 <VFM_ESINFO> : Entered. offset(0x0000000640C76200), len(0x0000000000010000)
       10/15/2010 18:51:03.0097 [TID 0x000016dc]: VixFile::write:h:\701\src\vxms\plugin\common\map\vix\VixFile.h:225 <VFM_ESINFO> : Calling vdWrite(sector_offset = (0x00000000032063B1), sector_count = (0x0000000000000080))
       10/15/2010 18:51:03.0315 [TID 0x000016dc]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : SAN: The specified request is invalid
       10/15/2010 18:51:03.0315 [TID 0x000016dc]: g_vdInterfaceLogger:.\libvix.cpp:1689 <VFM_ESINFO> : DISKLIB-LIB   : RWv failed ioId: #368416 (318) (62) .
       10/15/2010 18:51:03.0315 [TID 0x000016dc]: VixFile::write:h:\701\src\vxms\plugin\common\map\vix\VixFile.h:230 <VFM_ESERROR> [Sys Error: No error] : vdWrite() error=1. Exiting
       10/15/2010 18:51:03.0315 [TID 0x000016dc]: VixCoordinator::vixMapWrite:.\VixCoordinator.cpp:1156 <VFM_ESERROR> [Sys Error: No error] : Exited with 11
       10/15/2010 18:51:03.0315 [TID 0x000016dc]: vix_map_write:.\libvix.cpp:1670 <VFM_ESINFO> : Exited with 11
End vfm_write: result(11)

hostd log on the ESX host:

[2010-11-11 18:12:33.274 65C60B90 error 'BlklistsvcPlugin' opID=db03ff57-b1] Block range 25612 (1) extends beyond the end of the underlying virtual disk.
[2010-11-11 18:12:33.274 65C60B90 info 'App' opID=db03ff57-b1] AdapterServer caught exception: 0e48af68
[2010-11-11 18:12:33.274 65C60B90 info 'Vmomi' opID=db03ff57-b1] Activation [N5Vmomi10ActivationE:0xe481c00] : Invoke done [allocateBlocks] on [vim.host.DiskManager.Lease:52096fa4-572d-d386-3bc0-96509a3776fd]
[2010-11-11 18:12:33.274 65C60B90 verbose 'Vmomi' opID=db03ff57-b1] Arg startBlock:
25612
[2010-11-11 18:12:33.274 65C60B90 verbose 'Vmomi' opID=db03ff57-b1] Arg numBlocks:
1
[2010-11-11 18:12:33.274 65C60B90 verbose 'Vmomi' opID=db03ff57-b1] Arg assureValid:
false
[2010-11-11 18:12:33.275 65C60B90 info 'Vmomi' opID=db03ff57-b1] Throw vmodl.fault.InvalidArgument
[2010-11-11 18:12:33.275 65C60B90 info 'Vmomi' opID=db03ff57-b1] Result:
(vmodl.fault.InvalidArgument) {
  dynamicType = <unset>, 
  faultCause = (vmodl.MethodFault) null, 
  invalidProperty = "", 
  msg = "", 
}


Cause



By default, VMFS uses 1MB  blocks, however it is possible to create disks that include a fraction of a VMFS block.  When using SAN transport mode to restore a thin disk, you can only restore up to the portion of the disk that is a factor of 1MB.  Consider a scenario where the source disk or backup size is 512.5 MB.  The restore will restore 512MB of the disk with SAN transport mode and fail to write the last .5MB.

VMware write up for the issue:
http://kb.vmware.com/kb/1035096

When writing using SAN mode during restore, disk size should be a multiple of the underlying VMFS block size, otherwise writes to the last fraction of a disk will fail. For example, if a datastore has 1MB block size and the virtual disk is 16.3MB large, the last 0.3MB will not get written and will fail with the Invalid Argument error. Your software must add 0.7MB of zeroes to complete the block. This caveat does not apply to eager-zeroed thick disk.

 


Solution



The below may help when performed to the same datastore the VM was backed up from, or a datastore with the same Block Size/Cluster Size.

Option 1:

Attempt to restore using SAN to the same datastore

Option 2:

Attempt to restore using NBD

Option 3:

To restore VMs that are experiencing this issue, please contact Symantec and reference ET2022987

Symantec Corporation has acknowledged that the above-mentioned issue is present in the current version(s) of the product(s) mentioned at the end of this article. Symantec Corporation is committed to product quality and satisfied customers.
This issue is currently being considered by Symantec Corporation to be addressed in a forthcoming Maintenance Pack, Release Update, or version of the product.  Please note that Symantec Corporation reserves the right to remove any fix from the targeted release if it does not pass quality assurance tests or introduces new risks to overall code stability.  Symantec's plans are subject to change and any action taken by you based on the above information or your reliance upon the above information is made at your own risk.  Please refer to the maintenance pack readme or contact NetBackup Enterprise Support to confirm this issue (ET2022987) was included in the maintenance pack. 
As future maintenance packs and release updates are released, please visit the following link for download and readme information: 
 http://www.symantec.com/enterprise/support/downloads.jsp?pid=15143

 




Article URL http://www.symantec.com/docs/TECH144235


Terms of use for this information are found in Legal Notices