ESXi 6.0U2 + Veeam Ent Plus 9.5 - delta files can't consolidate

[metrans]

Hello,

I have little problem, a last night Veeam Enterprise Plus 9.5 backed up VM, but after finish does not consolidate delta files.

I can't consolidate delta files manually, I can't consolidate delta files if VM is powered on and powered off too, I try move vm to another hypervisor, but same problem.

ESXi 6.0U2 HP customized (build : 3620759) - standard edition

vCenter standard : VCSA

Storage : NetApp FAS2552 - ONTAP: 8.3.2

Server : HP DL 380G9

Server-Storage connection : 2x10Gbit NIC + NFS 4.1

VM : Windows Server 2012R2, VM HW Version : 8, 1x40GiB hdd, 1x 800GiB hdd, 1x vmxnet3

Problem with delta files is with 40GB hdd (fortunately).

If I run snapshot consolidation, then vCenter give me back this error :

An error occured while consolidating disks: 110 (Connection timed out).

Access to storage is ok, VM is up and write data to delta files.

Log in dmesg :

2016-12-09T21:50:07.070Z cpu18:34909 opID=ef13506c)<3>bnx2fc::: bnx2fc_fcoe_create:3489 phys_dev is QLogic device

2016-12-09T21:50:07.679Z cpu41:33527)<6>host3: fip: host3: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:07.679Z cpu41:33527)<6>host3: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:07.760Z cpu10:33523)<6>host4: fip: host4: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:07.760Z cpu10:33523)<6>host4: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:08.724Z cpu18:34911 opID=b9b252ef)World: 15516: VC opID bb95cb0d maps to vmkernel opID b9b252ef

2016-12-09T21:50:08.724Z cpu18:34911 opID=b9b252ef)<3>bnx2fc::: bnx2fc_fcoe_create:3459 phys_dev 0x4307d62e5cc0, cna device 0x4307d62ed920, vlan_id 0

2016-12-09T21:50:08.724Z cpu18:34911 opID=b9b252ef)<3>bnx2fc::: bnx2fc_fcoe_create:3472 check if it's QLogic device phys_dev 0x4307d62e5cc0

2016-12-09T21:50:08.724Z cpu18:34911 opID=b9b252ef)<3>bnx2fc::: bnx2fc_fcoe_create:3489 phys_dev is QLogic device

2016-12-09T21:50:09.679Z cpu0:33524)<6>host3: fip: host3: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:09.679Z cpu0:33524)<6>host3: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:09.760Z cpu0:33529)<6>host4: fip: host4: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:09.760Z cpu0:33529)<6>host4: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:10.429Z cpu17:33611)NMP: nmp_ResetDeviceLogThrottling:3349: last error status from device naa.600508b1001cbcdd73a1efc4f324e05c repeated 1 times

2016-12-09T21:50:11.679Z cpu8:33515)<6>host3: fip: host3: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:11.679Z cpu8:33515)<6>host3: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:11.761Z cpu0:33516)<6>host4: fip: host4: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:11.761Z cpu0:33516)<6>host4: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:13.680Z cpu38:33530)<6>host3: fip: host3: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:13.680Z cpu38:33530)<6>host3: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:13.762Z cpu10:33512)<6>host4: fip: host4: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:13.762Z cpu10:33512)<6>host4: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:14.755Z cpu0:34708 opID=9a8f00e4)World: 15516: VC opID HB-SpecSync-host-9@0-2c8bb0f9-9-cb25 maps to vmkernel opID 9a8f00e4

2016-12-09T21:50:14.755Z cpu0:34708 opID=9a8f00e4)Config: 681: "HostLocalSwapDirEnabled" = 0, Old Value: 0, (Status: 0x0)

2016-12-09T21:50:14.963Z cpu38:34464)NFS: 1833: Invalid shares: 0

2016-12-09T21:50:14.979Z cpu38:34464)NFS: 1833: Invalid shares: 0

2016-12-09T21:50:14.989Z cpu36:34464)NFS: 1833: Invalid shares: 0

2016-12-09T21:50:15.665Z cpu46:33507)<6>host3: fip: link down.

2016-12-09T21:50:15.665Z cpu46:33507)<6>host3: libfc: Link down on port (     0)

2016-12-09T21:50:15.665Z cpu46:33507)<3>bnx2fc:vmhba32:0000:04:00.0: bnx2fc_vlan_disc_cmpl:273 vmnic4: vlan_disc_cmpl: hba is on vlan_id 1002

2016-12-09T21:50:15.665Z cpu46:33507)<6>host3: libfc: Link up on port (     0)

2016-12-09T21:50:15.745Z cpu33:33510)<6>host4: fip: link down.

2016-12-09T21:50:15.745Z cpu33:33510)<6>host4: libfc: Link down on port (     0)

2016-12-09T21:50:15.745Z cpu33:33510)<3>bnx2fc:vmhba33:0000:04:00.1: bnx2fc_vlan_disc_cmpl:273 vmnic5: vlan_disc_cmpl: hba is on vlan_id 1002

2016-12-09T21:50:15.745Z cpu33:33510)<6>host4: libfc: Link up on port (     0)

2016-12-09T21:50:24.876Z cpu42:36634 opID=1335293d)World: 15516: VC opID HB-SpecSync-host-9@207-5cb59234-9a-cc0c maps to vmkernel opID 1335293d

2016-12-09T21:50:24.876Z cpu42:36634 opID=1335293d)Config: 681: "HostLocalSwapDirEnabled" = 0, Old Value: 0, (Status: 0x0)

2016-12-09T21:50:30.697Z cpu26:34708 opID=fb94915e)World: 15516: VC opID 0710B4D2-0002593E-76-c5-cc13 maps to vmkernel opID fb94915e

2016-12-09T21:50:30.697Z cpu26:34708 opID=fb94915e)NFS41: NFS41FileOpenFile:2783: Open of 0x43036dea2ee0 with openFlags 0x8 failed: Busy

2016-12-09T21:50:33.699Z cpu26:34708 opID=fb94915e)NFS41: NFS41FileOpenFile:2783: Open of 0x43036dea2ee0 with openFlags 0x8 failed: Busy

2016-12-09T21:50:35.657Z cpu64:33509)<6>host3: fip: link down.

2016-12-09T21:50:35.657Z cpu64:33509)<6>host3: libfc: Link down on port (     0)

2016-12-09T21:50:35.657Z cpu64:33509)fcoe_ctlr_link_up: setting fabric mode for vmnic4

2016-12-09T21:50:35.657Z cpu64:33509)<6>host3: libfc: Link up on port (     0)

2016-12-09T21:50:35.657Z cpu64:33509)<6>host3: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:35.737Z cpu0:33520)<6>host4: fip: link down.

2016-12-09T21:50:35.737Z cpu0:33520)<6>host4: libfc: Link down on port (     0)

2016-12-09T21:50:35.737Z cpu0:33520)fcoe_ctlr_link_up: setting fabric mode for vmnic5

2016-12-09T21:50:35.737Z cpu0:33520)<6>host4: libfc: Link up on port (     0)

2016-12-09T21:50:35.737Z cpu0:33520)<6>host4: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:36.700Z cpu26:34708 opID=fb94915e)NFS41: NFS41FileOpenFile:2783: Open of 0x43036dea2ee0 with openFlags 0x8 failed: Busy

2016-12-09T21:50:37.657Z cpu66:33533)<6>host3: fip: host3: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:37.657Z cpu66:33533)<6>host3: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:37.738Z cpu71:33508)<6>host4: fip: host4: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:37.738Z cpu71:33508)<6>host4: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:39.658Z cpu4:33514)<6>host3: fip: host3: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:39.658Z cpu4:33514)<6>host3: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:39.701Z cpu26:34708 opID=fb94915e)NFS41: NFS41FileOpenFile:2783: Open of 0x43036dea2ee0 with openFlags 0x8 failed: Busy

2016-12-09T21:50:39.736Z cpu38:37269)VmkAccess: 207: ipAddr = 0.0.0.0, port = 0

2016-12-09T21:50:39.736Z cpu38:37269)VmkAccess: 207: ipAddr = 0.0.0.0, port = 981

2016-12-09T21:50:39.739Z cpu64:33506)<6>host4: fip: host4: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:39.739Z cpu64:33506)<6>host4: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:41.659Z cpu2:33526)<6>host3: fip: host3: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:41.659Z cpu2:33526)<6>host3: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:41.740Z cpu36:33531)<6>host4: fip: host4: FIP VLAN ID unavail. Retry VLAN discovery.

2016-12-09T21:50:41.740Z cpu36:33531)<6>host4: fip: fcoe_ctlr_vlan_request() is done

2016-12-09T21:50:42.703Z cpu26:34708 opID=fb94915e)NFS41: NFS41FileOpenFile:2783: Open of 0x43036dea2ee0 with openFlags 0x8 failed: Busy

List of VM files :

[root@hv12-ph] ls -l /vmfs/volumes/vol_dat_fs_01/FS1-PH/
total 781070764
-rw-r--r--    1 root     root       2621952 Dec  9 15:12 FS1-PH-000001-ctk.vmdk
-rwxr-xr-x    1 root     root     318853120 Dec  9 01:38 FS1-PH-000001-delta.vmdk
-rwxr-xr-x    1 root     root           403 Dec  9 13:52 FS1-PH-000001.vmdk
-rwxr-xr-x    1 root     root      16863232 Dec  9 00:03 FS1-PH-000002-delta.vmdk
-rwxr-xr-x    1 root     root           315 Dec  9 01:36 FS1-PH-000002.vmdk
-rw-r--r--    1 root     root       2621952 Dec  9 15:12 FS1-PH-000003-ctk.vmdk
-rwxr-xr-x    1 root     root      33640448 Dec  9 01:39 FS1-PH-000003-delta.vmdk
-rwxr-xr-x    1 root     root           410 Dec  9 13:52 FS1-PH-000003.vmdk
-rw-r--r--    1 root     root       2621952 Dec  9 15:12 FS1-PH-000004-ctk.vmdk
-rwxr-xr-x    1 root     root      67194880 Dec  9 01:53 FS1-PH-000004-delta.vmdk
-rwxr-xr-x    1 root     root           410 Dec  9 13:52 FS1-PH-000004.vmdk
-rw-r--r--    1 root     root       2621952 Dec  9 15:12 FS1-PH-000005-ctk.vmdk
-rwxr-xr-x    1 root     root     604065792 Dec  9 05:42 FS1-PH-000005-delta.vmdk
-rwxr-xr-x    1 root     root           410 Dec  9 13:52 FS1-PH-000005.vmdk
-rw-r--r--    1 root     root       2621952 Dec  9 15:12 FS1-PH-000006-ctk.vmdk
-rwxr-xr-x    1 root     root      16863232 Dec  9 05:42 FS1-PH-000006-delta.vmdk
-rwxr-xr-x    1 root     root           410 Dec  9 13:52 FS1-PH-000006.vmdk
-rw-r--r--    1 root     root       2621952 Dec  9 15:12 FS1-PH-000007-ctk.vmdk
-rwxr-xr-x    1 root     root     906055680 Dec  9 09:45 FS1-PH-000007-delta.vmdk
-rwxr-xr-x    1 root     root           410 Dec  9 13:52 FS1-PH-000007.vmdk
-rw-r--r--    1 root     root       2621952 Dec  9 15:12 FS1-PH-000008-ctk.vmdk
-rwxr-xr-x    1 root     root      16863232 Dec  9 09:45 FS1-PH-000008-delta.vmdk
-rwxr-xr-x    1 root     root           410 Dec  9 13:52 FS1-PH-000008.vmdk
-rw-r--r--    1 root     root       2621952 Dec  9 15:12 FS1-PH-000009-ctk.vmdk
-rwxr-xr-x    1 root     root     1124159488 Dec  9 13:50 FS1-PH-000009-delta.vmdk
-rwxr-xr-x    1 root     root           410 Dec  9 13:52 FS1-PH-000009.vmdk
-rw-r--r--    1 root     root       2621952 Dec  9 15:12 FS1-PH-000010-ctk.vmdk
-rwxr-xr-x    1 root     root      33640448 Dec  9 13:51 FS1-PH-000010-delta.vmdk
-rwxr-xr-x    1 root     root           410 Dec  9 13:52 FS1-PH-000010.vmdk
-rw-r--r--    1 root     root       2621952 Dec  9 21:52 FS1-PH-000011-ctk.vmdk
-rwxr-xr-x    1 root     root     1711362048 Dec  9 23:17 FS1-PH-000011-delta.vmdk
-rwxr-xr-x    1 root     root           387 Dec  9 21:52 FS1-PH-000011.vmdk
-rwxr-xr-x    1 root     root           951 Nov  6 00:08 FS1-PH-50701506.hlog
-rwxr-xr-x    1 root     root     8589934592 Dec  9 21:52 FS1-PH-882972e8.vswp
-rwxr-xr-x    1 root     root            13 Dec  9 13:53 FS1-PH-aux.xml
-rw-r--r--    1 root     root       2621952 Dec  9 15:13 FS1-PH-ctk.vmdk
-rw-------    1 root     root     42949672960 Dec  9 00:02 FS1-PH-flat.vmdk
-rwxr-xr-x    1 root     root          8684 Dec  9 21:52 FS1-PH.nvram
-rwxr-xr-x    1 root     root           574 Dec  8 00:59 FS1-PH.vmdk
-rwxr-xr-x    1 root     root            78 Dec  9 13:52 FS1-PH.vmsd
-rwxr-xr-x    1 root     root          3887 Dec  9 21:52 FS1-PH.vmx
-rwxr-xr-x    1 root     root             0 Dec  9 21:52 FS1-PH.vmx.lck
-rw-r--r--    1 root     root       6554112 Dec  9 21:52 FS1-PH_1-ctk.vmdk
-rw-------    1 root     root     858993459200 Dec  9 23:17 FS1-PH_1-flat.vmdk
-rwxr-xr-x    1 root     root           582 Dec  9 21:53 FS1-PH_1.vmdk
-rwxr-xr-x    1 root     root        572159 Nov  5 20:18 vmware-1.log
-rwxr-xr-x    1 root     root        620918 Nov  5 20:18 vmware-2.log
-rwxr-xr-x    1 root     root        403495 Nov  5 20:18 vmware-3.log
-rwxr-xr-x    1 root     root        292382 Nov  5 20:18 vmware-4.log
-rwxr-xr-x    1 root     root       1109451 Nov  5 20:18 vmware-5.log
-rwxr-xr-x    1 root     root       2828315 Dec  9 21:27 vmware-6.log
-rwxr-xr-x    1 root     root        283558 Dec  9 21:56 vmware.log
-rwxr-xr-x    1 root     root     171966464 Dec  9 21:52 vmx-FS1-PH-2284417768-1.vswp

Anyone know where the problem could be?

Thank you

Max Devaine

[metrans]

Hello,

I found where is a problem. Its look like Veeam problem, because Veeam VM had mapped FS1-PH delta file 0002, see attachment.

I don't know why.

Its look very strange. This delta file is mapped to VM, so Windows see this disk and can write to them.

I am afraid that if I unplug this delta file from Veeam VM and then run consolidate FS1-PH, the result will be inconsistent FS1-PH :-/.

Otherwise the file is not changed, so maybe will be this file consistent, see (still old date):

-rwxr-xr-x    1 root     root      16863232 Dec  9 00:03 FS1-PH-000002-delta.vmdk
-rwxr-xr-x    1 root     root           315 Dec  9 01:36 FS1-PH-000002.vmdk

Max

[metrans · Accepted solution]

Ok, problem solved. Delta disk from Veeam is unplugged and consolidation snapshot is complete and all is ok.

Still I don't know why Veeam did it :-/.

Max