I can't consolidate disks of virtual mashine after using of veeam backup software. Now I have following I/o error on 19% of consolidation. In log file I have following.
2018-03-29T02:57:07.685Z| vmx| I120: SnapshotVMX_Consolidate: Starting
2018-03-29T02:57:07.685Z| vmx| I120: SnapshotVMXConsolidateOnlineCB: nextState = 0 uid 0
2018-03-29T02:57:07.685Z| vmx| I120: Turning on snapshot info cache. VM=xyzDB.xyz.vmx.
2018-03-29T02:57:07.695Z| vmx| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003-delta.vmdk" : open successful (65557) size = 874046439424, hd = 0. Type 8
2018-03-29T02:57:07.695Z| vmx| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003-delta.vmdk" : closed.
2018-03-29T02:57:07.695Z| vmx| I120: SNAPSHOT: Turning on snapshot disk cache.
2018-03-29T02:57:07.696Z| vmx| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003-delta.vmdk" : open successful (21) size = 874046439424, hd = 0. Type 8
2018-03-29T02:57:07.696Z| vmx| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003-delta.vmdk" : closed.
2018-03-29T02:57:07.696Z| vmx| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000001-delta.vmdk" : open successful (21) size = 203125571584, hd = 0. Type 8
2018-03-29T02:57:07.696Z| vmx| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000001-delta.vmdk" : closed.
2018-03-29T02:57:07.696Z| vmx| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000002-delta.vmdk" : open successful (21) size = 38759186432, hd = 0. Type 8
2018-03-29T02:57:07.696Z| vmx| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000002-delta.vmdk" : closed.
2018-03-29T02:57:07.697Z| vmx| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-flat.vmdk" : open successful (21) size = 1999001092096, hd = 0. Type 3
2018-03-29T02:57:07.697Z| vmx| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-flat.vmdk" : closed.
2018-03-29T02:57:07.697Z| vmx| I120: Vix: [75543394 mainDispatch.c:3964]: VMAutomation_ReportPowerOpFinished: statevar=3, newAppState=1880, success=1 additionalError=0
2018-03-29T02:57:07.697Z| vcpu-0| I120: Destroying virtual dev for scsi0:0 vscsi=9177
2018-03-29T02:57:07.697Z| vcpu-0| I120: VMMon_VSCSIStopVports: No such target on adapter
2018-03-29T02:57:07.717Z| vcpu-0| I120: SnapshotVMXConsolidateOnlineCB: nextState = 1 uid 0
2018-03-29T02:57:07.717Z| vcpu-0| I120: Closing all the disks of the VM.
2018-03-29T02:57:07.717Z| vcpu-0| I120: Closing disk scsi0:0
2018-03-29T02:57:07.719Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 1019433325.
2018-03-29T02:57:07.719Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2018-03-29T02:57:07.783Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003-delta.vmdk" : closed.
2018-03-29T02:57:07.795Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000001-delta.vmdk" : closed.
2018-03-29T02:57:07.803Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000002-delta.vmdk" : closed.
2018-03-29T02:57:07.811Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-flat.vmdk" : closed.
2018-03-29T02:57:07.811Z| vcpu-0| I120: SnapshotVMXConsolidateOnlineCB: nextState = 1 uid 0
2018-03-29T02:57:07.811Z| vcpu-0| I120: Checkpoint_Unstun: vm stopped for 114443 us
2018-03-29T02:57:07.812Z| vcpu-0| I120: SCSI: switching scsi0 to push completion mode
2018-03-29T02:57:07.813Z| vcpu-0| A115: ConfigDB: Setting scsi0:0.redo = ""
2018-03-29T02:57:07.813Z| vcpu-0| I120: DISK: OPEN scsi0:0 '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk' persistent R[]
2018-03-29T02:57:07.831Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003-delta.vmdk" : open successful (8) size = 874046439424, hd = 991842672. Type 8
2018-03-29T02:57:07.831Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "xyzDB.xyz-000003-delta.vmdk" (0x8)
2018-03-29T02:57:07.831Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk' (0x8): vmfsSparse, 3904299008 sectors / 1.8 TB.
2018-03-29T02:57:07.831Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2018-03-29T02:57:07.831Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 991842672, extentType = 0
2018-03-29T02:57:07.831Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2018-03-29T02:57:07.845Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 991842672.
2018-03-29T02:57:07.845Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 39ca5171-cbt.
2018-03-29T02:57:07.845Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/39ca5171-cbt
2018-03-29T02:57:07.845Z| vcpu-0| I120: DISKLIB-LIB : Opened "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk" (flags 0x8, type vmfsSparse).
2018-03-29T02:57:07.856Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000001-delta.vmdk" : open successful (8) size = 203125571584, hd = 962089332. Type 8
2018-03-29T02:57:07.856Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "xyzDB.xyz-000001-delta.vmdk" (0x8)
2018-03-29T02:57:07.856Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000001.vmdk' (0x8): vmfsSparse, 3904299008 sectors / 1.8 TB.
2018-03-29T02:57:07.856Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2018-03-29T02:57:07.856Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 962089332, extentType = 0
2018-03-29T02:57:07.857Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2018-03-29T02:57:07.864Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 962089332.
2018-03-29T02:57:07.864Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 38835175-cbt.
2018-03-29T02:57:07.864Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/38835175-cbt
2018-03-29T02:57:07.864Z| vcpu-0| I120: DISKLIB-LIB : Opened "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000001.vmdk" (flags 0x8, type vmfsSparse).
2018-03-29T02:57:07.866Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 991842672.
2018-03-29T02:57:07.866Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2018-03-29T02:57:07.868Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 962089332.
2018-03-29T02:57:07.868Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2018-03-29T02:57:07.885Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 2, numSubChains = 1
2018-03-29T02:57:07.885Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 962089332, extentType = 0
2018-03-29T02:57:07.885Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 991842672, extentType = 0
2018-03-29T02:57:07.885Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 991842672.
2018-03-29T02:57:07.885Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 38855175-cbt.
2018-03-29T02:57:07.886Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/38855175-cbt
2018-03-29T02:57:07.916Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000002-delta.vmdk" : open successful (8) size = 38759186432, hd = 1004491128. Type 8
2018-03-29T02:57:07.916Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "xyzDB.xyz-000002-delta.vmdk" (0x8)
2018-03-29T02:57:07.916Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000002.vmdk' (0x8): vmfsSparse, 3904299008 sectors / 1.8 TB.
2018-03-29T02:57:07.916Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2018-03-29T02:57:07.916Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 1004491128, extentType = 0
2018-03-29T02:57:07.917Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2018-03-29T02:57:07.924Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 1004491128.
2018-03-29T02:57:07.924Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 3ac15179-cbt.
2018-03-29T02:57:07.924Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/3ac15179-cbt
2018-03-29T02:57:07.924Z| vcpu-0| I120: DISKLIB-LIB : Opened "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000002.vmdk" (flags 0x8, type vmfsSparse).
2018-03-29T02:57:07.926Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 991842672.
2018-03-29T02:57:07.926Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2018-03-29T02:57:07.928Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 1004491128.
2018-03-29T02:57:07.928Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2018-03-29T02:57:07.945Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 3, numSubChains = 1
2018-03-29T02:57:07.945Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 1004491128, extentType = 0
2018-03-29T02:57:07.945Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 962089332, extentType = 0
2018-03-29T02:57:07.945Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(2) fid = 991842672, extentType = 0
2018-03-29T02:57:07.946Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 991842672.
2018-03-29T02:57:07.946Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 3ac35179-cbt.
2018-03-29T02:57:07.946Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/3ac35179-cbt
2018-03-29T02:57:07.986Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-flat.vmdk" : open successful (522) size = 1999001092096, hd = 988828027. Type 3
2018-03-29T02:57:07.986Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "xyzDB.xyz-flat.vmdk" (0x20a)
2018-03-29T02:57:07.986Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz.vmdk' (0x20a): vmfs, 3904299008 sectors / 1.8 TB.
2018-03-29T02:57:07.986Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2018-03-29T02:57:08.014Z| vcpu-0| I120: DISKLIB-CTK : Could not open change tracking file "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-ctk.vmdk": Change tracking invalid or disk in use.
2018-03-29T02:57:08.014Z| vcpu-0| I120: DISKLIB-CTK : Re-initializing change tracking.
2018-03-29T02:57:08.014Z| vcpu-0| I120: DISKLIB-CTK : Auto blocksize for size 3904299008 is 2048.
2018-03-29T02:57:08.015Z| vcpu-0| I120: OBJLIB-FILEBE : Error creating file '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-ctk.vmdk': 3 (The file already exists).
2018-03-29T02:57:08.015Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 988828027.
2018-03-29T02:57:08.015Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 3af0517b-cbt.
2018-03-29T02:57:08.015Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/3af0517b-cbt
2018-03-29T02:57:08.015Z| vcpu-0| I120: DISKLIB-LIB : Opened "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz.vmdk" (flags 0x20a, type vmfs).
2018-03-29T02:57:08.017Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 991842672.
2018-03-29T02:57:08.017Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2018-03-29T02:57:08.019Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 988828027.
2018-03-29T02:57:08.019Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2018-03-29T02:57:08.035Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 4, numSubChains = 1
2018-03-29T02:57:08.036Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 988828027, extentType = 2
2018-03-29T02:57:08.036Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 1004491128, extentType = 0
2018-03-29T02:57:08.036Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(2) fid = 962089332, extentType = 0
2018-03-29T02:57:08.036Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(3) fid = 991842672, extentType = 0
2018-03-29T02:57:08.054Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 991842672.
2018-03-29T02:57:08.054Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 3ac55179-cbt.
2018-03-29T02:57:08.054Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/3ac55179-cbt
2018-03-29T02:57:08.055Z| vcpu-0| I120: DISK: Disk '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk' has UUID '60 00 c2 9f cd c1 d5 72-86 e5 29 ab e3 15 c6 f4'
2018-03-29T02:57:08.055Z| vcpu-0| I120: DISK: OPEN '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk' Geo (243031/255/63) BIOS Geo (0/0/0)
2018-03-29T02:57:08.055Z| vcpu-0| I120: Creating virtual dev for scsi0:0
2018-03-29T02:57:08.055Z| vcpu-0| I120: DumpDiskInfo: scsi0:0 createType=11, capacity = 3904299008, numLinks = 4, allocationType = 0
2018-03-29T02:57:08.055Z| vcpu-0| I120: SCSIDiskESXPopulateVDevDesc: Using FS backend
2018-03-29T02:57:08.055Z| vcpu-0| I120: DISKUTIL: scsi0:0 : geometry=243031/255/63
2018-03-29T02:57:08.057Z| vcpu-0| I120: SnapshotVMXConsolidateOnlineCB: nextState = 2 uid 0
2018-03-29T02:57:08.057Z| SnapshotVMXCombiner| I120: VTHREAD start thread 14 "SnapshotVMXCombiner" pid 75544762
2018-03-29T02:57:08.057Z| SnapshotVMXCombiner| I120: SnapshotVMXConsolidateOnlineCB: nextState = 3 uid 0
2018-03-29T02:57:08.057Z| SnapshotVMXCombiner| I120: SnapshotVMXConsolidateOnlineCB: Starting combine of scsi0:0 /vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk. 3 links, starting from 1
2018-03-29T02:57:08.057Z| vcpu-0| I120: SnapshotVMXConsolidateOnlineCB: Created thread 14 for scsi0:0
2018-03-29T02:57:08.127Z| vcpu-6| I120: HBACommon: First write on scsi0:0.fileName='/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk'
2018-03-29T02:57:08.127Z| vcpu-6| I120: DDB: "longContentID" = "ad5119fec08f0525a6c2ee87761ff5e5" (was "d1c3090360d1f9a387a1358d41957106")
2018-03-29T02:57:08.261Z| vcpu-6| I120: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x41957106, new=0x761ff5e5 (ad5119fec08f0525a6c2ee87761ff5e5)
2018-03-29T02:57:08.262Z| SnapshotVMXCombiner| I120: DISKLIB-LIB : Upward Combine 3 links at 1. Need 1906396 MB of free space (2805172 MB available)
2018-03-29T02:57:08.298Z| SnapshotVMXCombiner| I120: DDB: "longContentID" = "f28f917eda5233e21d1803a81b19952e" (was "e3fb3a5abe350337d652bf02e93cac04")
2018-03-29T02:57:08.344Z| SnapshotVMXCombiner| I120: DDB: "longContentID" = "e3fb3a5abe350337d652bf02e93cac04" (was "f28f917eda5233e21d1803a81b19952e")
2018-03-29T03:37:28.739Z| SnapshotVMXCombiner| I120: OBJLIB-FILEBE : FileBEIoctl: ioctl operation failed on '/vmfs/devices/deltadisks/17ebc38d-xyzDB.xyz-000003-delta.vmdk' : Input/output error (327682)
2018-03-29T03:37:28.739Z| SnapshotVMXCombiner| I120: DISKLIB-VMFS_SPARSE : VmfsSparseExtentCombine: failed: for 2 level and start 615430 Input/output error.
2018-03-29T03:37:28.739Z| SnapshotVMXCombiner| I120: DISKLIB-CTK : End Combine
2018-03-29T03:37:28.739Z| SnapshotVMXCombiner| I120: DISKLIB-CTK : Attempting unlink of (null)
2018-03-29T03:37:28.739Z| SnapshotVMXCombiner| I120: SnapshotVMXCombineFinalCb: Done with combine of 3 links, starting from 1 in 2420682332 usec with error 0x50009: Input/output error
2018-03-29T03:37:31.752Z| vcpu-0| I120: Destroying virtual dev for scsi0:0 vscsi=9178
2018-03-29T03:37:31.752Z| vcpu-0| I120: VMMon_VSCSIStopVports: No such target on adapter
2018-03-29T03:37:31.809Z| vcpu-0| I120: SnapshotVMXConsolidateOnlineCB: nextState = 4 uid 0
2018-03-29T03:37:31.809Z| vcpu-0| I120: Closing disk scsi0:0
2018-03-29T03:37:31.811Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 991842672.
2018-03-29T03:37:31.812Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2018-03-29T03:37:31.927Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003-delta.vmdk" : closed.
2018-03-29T03:37:31.928Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000001-delta.vmdk" : closed.
2018-03-29T03:37:31.928Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000002-delta.vmdk" : closed.
2018-03-29T03:37:31.928Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-flat.vmdk" : closed.
2018-03-29T03:37:31.928Z| vcpu-0| I120: SnapshotVMXNeedConsolidateIteration : Invalid consolidateRate (4294967296.000000 MBps), not branching any more
2018-03-29T03:37:31.928Z| vcpu-0| I120: SnapshotVMXNeedConsolidateIteration: Another iteration of helper branch is not needed.
2018-03-29T03:37:31.939Z| vcpu-0| I120: Checkpoint_Unstun: vm stopped for 3199928 us
2018-03-29T03:37:31.940Z| vcpu-0| I120: SCSI: switching scsi0 to push completion mode
2018-03-29T03:37:31.941Z| vcpu-0| A115: ConfigDB: Setting scsi0:0.redo = ""
2018-03-29T03:37:31.941Z| vcpu-0| I120: DISK: OPEN scsi0:0 '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk' persistent R[]
2018-03-29T03:37:31.967Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003-delta.vmdk" : open successful (10) size = 874063216640, hd = 988959099. Type 8
2018-03-29T03:37:31.967Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "xyzDB.xyz-000003-delta.vmdk" (0xa)
2018-03-29T03:37:31.967Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk' (0xa): vmfsSparse, 3904299008 sectors / 1.8 TB.
2018-03-29T03:37:31.984Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000001-delta.vmdk" : open successful (14) size = 203125571584, hd = 965431677. Type 8
2018-03-29T03:37:31.984Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "xyzDB.xyz-000001-delta.vmdk" (0xe)
2018-03-29T03:37:31.984Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000001.vmdk' (0xe): vmfsSparse, 3904299008 sectors / 1.8 TB.
2018-03-29T03:37:32.019Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000002-delta.vmdk" : open successful (14) size = 38759186432, hd = 967463294. Type 8
2018-03-29T03:37:32.019Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "xyzDB.xyz-000002-delta.vmdk" (0xe)
2018-03-29T03:37:32.019Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000002.vmdk' (0xe): vmfsSparse, 3904299008 sectors / 1.8 TB.
2018-03-29T03:37:32.048Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-flat.vmdk" : open successful (14) size = 1999001092096, hd = 976966015. Type 3
2018-03-29T03:37:32.048Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "xyzDB.xyz-flat.vmdk" (0xe)
2018-03-29T03:37:32.048Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz.vmdk' (0xe): vmfs, 3904299008 sectors / 1.8 TB.
2018-03-29T03:37:32.048Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 4, numSubChains = 1
2018-03-29T03:37:32.048Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 976966015, extentType = 2
2018-03-29T03:37:32.048Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 967463294, extentType = 0
2018-03-29T03:37:32.048Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(2) fid = 965431677, extentType = 0
2018-03-29T03:37:32.048Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(3) fid = 988959099, extentType = 0
2018-03-29T03:37:32.058Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2018-03-29T03:37:32.093Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 988959099.
2018-03-29T03:37:32.093Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 3a715180-cbt.
2018-03-29T03:37:32.093Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/3a715180-cbt
2018-03-29T03:37:32.093Z| vcpu-0| I120: DISKLIB-LIB : Opened "/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk" (flags 0xa, type vmfs).
2018-03-29T03:37:32.093Z| vcpu-0| I120: DISK: Disk '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk' has UUID '60 00 c2 9f cd c1 d5 72-86 e5 29 ab e3 15 c6 f4'
2018-03-29T03:37:32.093Z| vcpu-0| I120: DISK: OPEN '/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk' Geo (243031/255/63) BIOS Geo (0/0/0)
2018-03-29T03:37:32.094Z| vcpu-0| I120: Creating virtual dev for scsi0:0
2018-03-29T03:37:32.094Z| vcpu-0| I120: DumpDiskInfo: scsi0:0 createType=11, capacity = 3904299008, numLinks = 4, allocationType = 0
2018-03-29T03:37:32.094Z| vcpu-0| I120: SCSIDiskESXPopulateVDevDesc: Using FS backend
2018-03-29T03:37:32.094Z| vcpu-0| I120: DISKUTIL: scsi0:0 : geometry=243031/255/63
2018-03-29T03:37:32.095Z| vcpu-0| I120: SnapshotVMXConsolidateOnlineCB: nextState = 6 uid 0
2018-03-29T03:37:32.095Z| vcpu-0| I120: Vix: [75477874 mainDispatch.c:3964]: VMAutomation_ReportPowerOpFinished: statevar=3, newAppState=1881, success=1 additionalError=0
2018-03-29T03:37:32.096Z| vcpu-0| I120: Locale_Errno2LocalString: "C" locale found. LC_ALL=(null), LANG=C
2018-03-29T03:37:32.096Z| vcpu-0| I120: Locale_Errno2LocalString: locale(LC_ALL)=C locale(LC_MESSAGES)=C
2018-03-29T03:37:32.096Z| vcpu-0| I120: SnapshotVMXConsolidateOnlineCB: Destroying thread 14
2018-03-29T03:37:32.096Z| vcpu-0| I120: Turning off snapshot info cache.
2018-03-29T03:37:32.096Z| vcpu-0| I120: Turning off snapshot disk cache.
2018-03-29T03:37:32.096Z| vcpu-0| I120: SnapshotVMXConsolidateOnlineCB: Done with consolidate
2018-03-29T03:37:32.120Z| vcpu-5| I120: HBACommon: First write on scsi0:0.fileName='/vmfs/volumes/586e1ffe-3ca22b38-d90e-0cc47a7fdf12/xyzDB.xyz/xyzDB.xyz-000003.vmdk'
2018-03-29T03:37:32.120Z| vcpu-5| I120: DDB: "longContentID" = "1bcfb84029cef153c7ad4d5df8be99d5" (was "ad5119fec08f0525a6c2ee87761ff5e5")
2018-03-29T03:37:32.181Z| vcpu-5| I120: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x761ff5e5, new=0xf8be99d5 (1bcfb84029cef153c7ad4d5df8be99d5)
2018-03-29T03:38:32.183Z| vmx| I120: GuestRpcSendTimedOut: message to toolbox-dnd timed out.
It looks as an issue with your local controller or hard driver.
One error is
2018-03-29T03:37:28.737Z cpu16:33570)<3>ata6.00: cmd 60/80:00:09:da:6e/01:00:0b:00:00/40 tag 0 ncq 196608 in
res 41/40:00:6b:da:6e/00:00:0b:00:00/40 Emask 0x409 (media error) <F>
The second error is
2018-03-29T03:37:28.739Z cpu22:32795)ScsiDeviceIO: 2338: Cmd(0x413680bc02c0) 0x28, CmdSN 0x62a11 from world 75543401 to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" failed H:0x3 D:0x0 P:0x0 Possible sense data: 0x0 0x$
2018-03-29T03:37:28.739Z cpu9:32814)ScsiDeviceIO: 2338: Cmd(0x412e84b634c0) 0x28, CmdSN 0x62a10 from world 75544762 to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x3 0x11 0$
and
2018-03-29T03:37:28.739Z cpu9:32814)ScsiDeviceIO: 2338: Cmd(0x412e84bbc300) 0x2a, CmdSN 0x62a12 from world 32797 to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" failed H:0x3 D:0x0 P:0x0 Possible sense data: 0x0 0x0 0x$
So basically when ESXi hosts tries to Read (0x28) and Write (0x2a) it gets in trouble.
The main is H:0x0 D:0x2 P:0x0 Valid sense data: 0x3 0x11 0$
It means:
0x3 - MEDIUM ERROR
0x11 0$ - UNRECOVERED READ ERROR
I suppose that your hard drive has bad blocks. And data can't be recovered from these blocks.
I recommend to migrate all data off this datastore and then check hard drive.
Hi!
There error is
2018-03-29T03:37:28.739Z| SnapshotVMXCombiner| I120: OBJLIB-FILEBE : FileBEIoctl: ioctl operation failed on '/vmfs/devices/deltadisks/17ebc38d-xyzDB.xyz-000003-delta.vmdk' : Input/output error (327682)
2018-03-29T03:37:28.739Z| SnapshotVMXCombiner| I120: DISKLIB-VMFS_SPARSE : VmfsSparseExtentCombine: failed: for 2 level and start 615430 Input/output error.
Can you check vmkernel.log on the same hosts according this timestamp?
2018-03-29T03:37:28.737Z cpu16:33570)<3>ata6.00: exception Emask 0x0 SAct 0xf SErr 0x0 action 0x0
2018-03-29T03:37:28.737Z cpu16:33570)<3>ata6.00: irq_stat 0x40000008
2018-03-29T03:37:28.737Z cpu16:33570)<3>ata6.00: cmd 60/80:00:09:da:6e/01:00:0b:00:00/40 tag 0 ncq 196608 in
res 41/40:00:6b:da:6e/00:00:0b:00:00/40 Emask 0x409 (media error) <F>
2018-03-29T03:37:28.737Z cpu16:33570)<3>ata6.00: status: { DRDY ERR }
2018-03-29T03:37:28.737Z cpu16:33570)<3>ata6.00: error: { UNC }
2018-03-29T03:37:28.739Z cpu14:33570)<6>ata6.00: configured for UDMA/133
2018-03-29T03:37:28.739Z cpu14:33570)<6>ata6: EH complete
2018-03-29T03:37:28.739Z cpu22:32795)NMP: nmp_ThrottleLogForDevice:2321: Cmd 0x28 (0x413680bc02c0, 75543401) to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" on path "vmhba35:C0:T0:L0" Failed: H:0x3 D:0x0 P:0x0 Possibl$
2018-03-29T03:37:28.739Z cpu22:32795)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" state in doubt; requested fast path state update...
2018-03-29T03:37:28.739Z cpu22:32795)ScsiDeviceIO: 2338: Cmd(0x413680bc02c0) 0x28, CmdSN 0x62a11 from world 75543401 to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" failed H:0x3 D:0x0 P:0x0 Possible sense data: 0x0 0x$
2018-03-29T03:37:28.739Z cpu9:32814)ScsiDeviceIO: 2338: Cmd(0x412e84b634c0) 0x28, CmdSN 0x62a10 from world 75544762 to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x3 0x11 0$
2018-03-29T03:37:28.739Z cpu22:32827)ScsiDeviceIO: 2338: Cmd(0x413682722740) 0x2a, CmdSN 0x62a13 from world 32797 to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" failed H:0x3 D:0x0 P:0x0 Possible sense data: 0x0 0x0 0$
2018-03-29T03:37:28.739Z cpu9:32814)ScsiDeviceIO: 2338: Cmd(0x412e84bbc300) 0x2a, CmdSN 0x62a12 from world 32797 to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" failed H:0x3 D:0x0 P:0x0 Possible sense data: 0x0 0x0 0x$
2018-03-29T03:37:28.739Z cpu8:75544762)Cow: 1579: Sync IO issued on cow disk 'xyzDB.xyz-000002-delta.vmdk' failed with I/O error
2018-03-29T03:37:28.739Z cpu8:75544762)WARNING: Cow: 878: COW Commit failed with I/O error
2018-03-29T03:37:28.839Z cpu9:75321384)World: 14299: VC opID hostd-fd35 maps to vmkernel opID 11dae047
It looks as an issue with your local controller or hard driver.
One error is
2018-03-29T03:37:28.737Z cpu16:33570)<3>ata6.00: cmd 60/80:00:09:da:6e/01:00:0b:00:00/40 tag 0 ncq 196608 in
res 41/40:00:6b:da:6e/00:00:0b:00:00/40 Emask 0x409 (media error) <F>
The second error is
2018-03-29T03:37:28.739Z cpu22:32795)ScsiDeviceIO: 2338: Cmd(0x413680bc02c0) 0x28, CmdSN 0x62a11 from world 75543401 to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" failed H:0x3 D:0x0 P:0x0 Possible sense data: 0x0 0x$
2018-03-29T03:37:28.739Z cpu9:32814)ScsiDeviceIO: 2338: Cmd(0x412e84b634c0) 0x28, CmdSN 0x62a10 from world 75544762 to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x3 0x11 0$
and
2018-03-29T03:37:28.739Z cpu9:32814)ScsiDeviceIO: 2338: Cmd(0x412e84bbc300) 0x2a, CmdSN 0x62a12 from world 32797 to dev "t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658" failed H:0x3 D:0x0 P:0x0 Possible sense data: 0x0 0x0 0x$
So basically when ESXi hosts tries to Read (0x28) and Write (0x2a) it gets in trouble.
The main is H:0x0 D:0x2 P:0x0 Valid sense data: 0x3 0x11 0$
It means:
0x3 - MEDIUM ERROR
0x11 0$ - UNRECOVERED READ ERROR
I suppose that your hard drive has bad blocks. And data can't be recovered from these blocks.
I recommend to migrate all data off this datastore and then check hard drive.
I've made copy of all files using scp command. On the xxx-000002-delta was i/o error during copy. on source datastore size of it: 36GB, on new datastore - 30GB. snapshot consolidation on new storage didn't worked as well. I think because there is 000002-delta corrupted. However I've started VM and move it using vsphere converter to new storage. I can't understand why VM working and can be converted but snapshot consolidation does not working for the same VM? And how can I check physical drives from vmware? "esxcli storage core device smart get" command showing approximately the same info for all drives:
~ # esxcli storage core device smart get --device-name=t10.ATA_____WDC_WD3000FYYZ2D01UL1B1_______________________WD2DWCC130783537
Parameter Value Threshold Worst
---------------------------- ----- --------- -----
Health Status OK N/A N/A
Media Wearout Indicator N/A N/A N/A
Write Error Count N/A N/A N/A
Read Error Count 200 51 200
Power-on Hours 74 0 74
Power Cycle Count 100 0 100
Reallocated Sector Count 200 140 200
Raw Read Error Rate 200 51 200
Drive Temperature 116 0 110
Driver Rated Max Temperature N/A N/A N/A
Write Sectors TOT Count 200 0 200
Read Sectors TOT Count 200 0 200
Initial Bad Block Count N/A N/A N/A
~ # esxcli storage core device smart get --device-name=t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130043658
Parameter Value Threshold Worst
---------------------------- ----- --------- -----
Health Status OK N/A N/A
Media Wearout Indicator N/A N/A N/A
Write Error Count N/A N/A N/A
Read Error Count 200 51 199
Power-on Hours 55 0 55
Power Cycle Count 100 0 100
Reallocated Sector Count 200 140 200
Raw Read Error Rate 200 51 199
Drive Temperature 121 0 110
Driver Rated Max Temperature N/A N/A N/A
Write Sectors TOT Count 200 0 200
Read Sectors TOT Count 200 0 200
Initial Bad Block Count N/A N/A N/A
~ # esxcli storage core device smart get --device-name=t10.ATA_____WDC_WD3000FYYZ2D01UL1B0_______________________WD2DWCC130018698
Parameter Value Threshold Worst
---------------------------- ----- --------- -----
Health Status OK N/A N/A
Media Wearout Indicator N/A N/A N/A
Write Error Count N/A N/A N/A
Read Error Count 200 51 200
Power-on Hours 47 0 47
Power Cycle Count 100 0 100
Reallocated Sector Count 200 140 200
Raw Read Error Rate 200 51 200
Drive Temperature 116 0 109
Driver Rated Max Temperature N/A N/A N/A
Write Sectors TOT Count 200 0 200
Read Sectors TOT Count 200 0 200
Initial Bad Block Count N/A N/A N/A
~ # esxcli storage core device smart get --device-name=t10.ATA_____WDC_WD3000FYYZ2D01UL1B1_______________________WD2DWCC130783537
Parameter Value Threshold Worst
---------------------------- ----- --------- -----
Health Status OK N/A N/A
Media Wearout Indicator N/A N/A N/A
Write Error Count N/A N/A N/A
Read Error Count 200 51 200
Power-on Hours 74 0 74
Power Cycle Count 100 0 100
Reallocated Sector Count 200 140 200
Raw Read Error Rate 200 51 200
Drive Temperature 116 0 110
Driver Rated Max Temperature N/A N/A N/A
Write Sectors TOT Count 200 0 200
Read Sectors TOT Count 200 0 200
Initial Bad Block Count N/A N/A N/A
Is the VM still working without problems ?
If yes - forget about consolidation.
Instead clone the complete snapshot-chain with ddrescue using a Linux LiveCD.
Power off the VM.
- add new disk to VM with the same size as the existing disk
- boot VM into a Linux LiveCD
- clone original disk to new disk with a command like:
ddrescue -f /dev/sda /dev/sdb /tmp/copy.log
(dev/sda = original disk)
(dev/sdb = new disk)
Make sure to create the copy.log !!!!