Slow Cross Cluster Clone operation when concurrent tasks are executed

Products

VMware vSphere ESXi VMware vCenter Server

Issue/Introduction

Elongated time frame is consumed when VM deployment and/or VM clone operation is initiated as a cross-cluster operation. The vCenter operation never fails, however, when vRA is involved during the deployment, the task is considered as failure when it exceeds the set timeout of 120 minutes.

/var/log/vmware/vpxd/vpxd.log

--> name = "Example-VM-1234",
--> folder = 'vim.Folder:######:group-ID',
--> spec = (vim.vm.CloneSpec) {
--> location = (vim.vm.RelocateSpec) {
--> folder = 'vim.Folder:######:group-ID',
--> datastore = 'vim.Datastore:######:datastore-####',
--> diskMoveType = "moveChildMostDiskBacking",
--> pool = 'vim.ResourcePool:######:resgroup-####',
--> disk = (vim.vm.RelocateSpec.DiskLocator) [
--> (vim.vm.RelocateSpec.DiskLocator) {
--> diskId = ####,
--> datastore = 'vim.Datastore:######:datastore-######',
--> diskBackingInfo = (vim.vm.device.VirtualDisk.FlatVer2BackingInfo) {
--> fileName = "[<example datastore>] datastore UUID/example vm_1.vmdk",
--> datastore = 'vim.Datastore:######:datastore-####',
--> backingObjectId = "#####",
--> diskMode = "persistent",
--> split = false,
--> writeThrough = false,
--> thinProvisioned = true,
--> eagerlyScrub = false,
--> uuid = "#######",
--> contentId = "#######",
--> digestEnabled = false,
--> sharing = "sharingNone",

yyyy-mm-ddThh:min: verbose vpxd[3341294] [Originator@6876 sub=pbm opID=29####-01] Completed pbm PreProvisionProcess
yyyy-mm-ddThh:min: verbose vpxd[3341294] [Originator@6876 sub=pbm opID=29####-01] Ending PreProvisionProcess with entityAssociations: (pbm.profile.EntityAssociations) {
--> operation = "CLONE",
--> entity = (pbm.ServerObjectRef) {
--> objectType = "virtualMachineAndDisks",
--> key = "vm-####",
--> },
--> entityName = "Example-VM-1234",
--> policyAssociations = (pbm.profile.PolicyAssociation) [
--> (pbm.profile.PolicyAssociation) {
--> entity = (pbm.ServerObjectRef) {
--> objectType = "virtualMachine",
--> key = "vm-####",
--> },
--> policySpec = (vim.vm.DefinedProfileSpec) {
--> profileId = "aa####ad",
--> profileData = (vim.vm.ProfileRawData) {
--> extensionKey = "com.vmware.vim.sps",

yyyy-mm-ddThh:min: info vpxd[3341294] [Originator@6876 sub=VmProv opID=29####-01] Local-VC Host Datastore Linked Clone of poweredOff VM 'example vm' (vm-##, ds:///vmfs/volumes/vsan:UUID/datastore UUID/example vm.vmtx) to new name Example-VM on host-id (host-ip) in pool resgroup-id with ds ds:///vmfs/volumes/vsan:UUID/ to host-id (host-ip) in pool resgroup-#### with ds ds:///vmfs/volumes/vsan:UUID/

yyyy-mm-ddThh:min info vpxd[3341294] [Originator@6876 sub=vpxdUtil opID=29####-01] [VmFileAccess] Operation: Copy, SrcFile: ds:///vmfs/volumes/vsan:UUID/####/example vm_1.vmdk, DstFile: ds:///vmfs/volumes/vsan:UUID/####/Example-VM_1.vmdk, User: Domain\username
yyyy-mm-ddThh:min info vpxd[3341294] [Originator@6876 sub=vpxdUtil opID=29####-01] [VmFileAccess] Operation: Copy, SrcFile: ds:///vmfs/volumes/vsan:UUID/####/example vm.nvram, DstFile: ds:///vmfs/volumes/vsan:UUID/####/Example-VM.nvram, User: Domain\username

Note: Make a note of the time stamp corresponding to the start of NFC session "NfcFile_Open" and completion of nfc_copy "reached EOF". The elongated time frame during this stage, needs to be reviewed from Network entity.

/var/run/log/hostd.log

yyyy-mm-ddThh:min In(166) Hostd[2103519]: [Originator@6876 sub=Libs opID=29####] [NFC INFO]Handle PUT Msg for file: /vmfs/volumes/vsan:UUID/####/Example-VM_1.vmdk. fileSize=##### spaceRequired=#####
yyyy-mm-ddThh:min In(166) Hostd[2103519]: [Originator@6876 sub=Libs opID=29####] [NFC INFO]NfcFile_Open: session=session id hdl=ED51F07C10 Local filename = '/vmfs/volumes/vsan:UUID/####/Example-VM_1.vmdk'

-------------- copy in-progress ----------------

yyyy-mm-ddThh:min In(166) Hostd[2103505]: [Originator@6876 sub=Libs opID=29####] [NFC INFO]NfcFile_ContinueReceive: reached EOF
yyyy-mm-ddThh:min In(166) Hostd[2103505]: [Originator@6876 sub=Vimsvc.ha-eventmgr opID=29####] Event 25880 : NFC operation 'Upload' for path '/vmfs/volumes/vsan:UUID/####/Example-VM_1.vmdk' was initiated from 'host-ip' and completed with status 'Success'
yyyy-mm-ddThh:min In(166) Hostd[2103505]: [Originator@6876 sub=Libs opID=29####] [NFC INFO]NfcFile_Close: session=session id hdl=ED51F07C10 filename='/vmfs/volumes/vsan:UUID/####/Example-VM_1.vmdk'
yyyy-mm-ddThh:min Db(167) Hostd[2103503]: [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/vsan:UUID/####/Example-VM.vmx opID=76####ee user=vpxuser:Domain\username] Reconfigure completed succesfully

Environment

vSphere 7.x and 8.x

Cause

Delay in file copy can be for various reasons, depending on available bandwidth, network congestion and/or incorrect MTU configuration.

Resolution

Determine the cause for network slowness by following the steps mentioned in