Unable to create VM's on NFS 4.1 Volume

[kclarksd83]

We're running ESXI 6.0 managed by vCenter 6, and connecting to a NetApp SAN for storage.

The NetApp has NFS 3 and 4.1 enabled. I've connected ESXI to one volume named vol_nfs_vmware_01 using NFS 3 and it's been working fine.

I connected ESXI to a second volume on the NetApp named vol_nfs_vmware_02 using NFS 4.1. It connects okay, I can browse the datastore, and create new folders / copy files onto the datastore fine.

The problem is that I can't actually create a new VM on the NFS 4.1 volume. Any time I try it comes back with an error "An error occurred while writing dictionary file "/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmx": 13 (Permission denied)."

I don't see how it can be permission denied, if I can browse the datastore and create file on it fine.

That same error comes up if I try to create the VM through vCenter (In the Java client or web client) or directly through ESXI using the java client. Also I tried migrating an exising VM from the 01 datastore to the 02 datastore and it was a similar error, permission denied.

I looked at vpxa.log and I see the same error come up but I have no idea where to start looking from there.

Here's part of vpxa.log: (Let me know if it would be helpful to have more above or below.)

2016-01-20T20:12:37.827Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5700b113] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2016-01-20T20:12:37.827Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5700b113] [WaitForUpdatesDone] Completed callback

2016-01-20T20:12:37.829Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalResourcePool opID=SWI-6e698304] [VpxaHalResourcePoolCurrentImpl::SetCachedRootResources] done

2016-01-20T20:12:37.829Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalResourcePool opID=SWI-6e698304] [VpxaHostdSpecSync] Copied root values ...

2016-01-20T20:12:37.829Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalResourcePool opID=SWI-6e698304] [ProcessResourceNotification] No syncs pending, exiting loop...

2016-01-20T20:12:37.835Z verbose vpxa[FFB39B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5118b43d] [WaitForUpdatesDone] Received callback

2016-01-20T20:12:37.835Z verbose vpxa[FFB39B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5118b43d] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 164280 to 164281 (at 164280)

2016-01-20T20:12:37.837Z verbose vpxa[FFB39B70] [Originator@6876 sub=hostdevent opID=WFU-5118b43d] Event vim.event.VmRemovedEvent ignored: username (vpxuser)

2016-01-20T20:12:37.838Z verbose vpxa[FFB39B70] [Originator@6876 sub=halservices opID=WFU-5118b43d] [VpxaHalServices] EventsRecorded Event Fired

2016-01-20T20:12:37.838Z verbose vpxa[FFB39B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5118b43d] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2016-01-20T20:12:37.838Z verbose vpxa[FFB39B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-5118b43d] [WaitForUpdatesDone] Completed callback

2016-01-20T20:12:37.840Z verbose vpxa[FFB39B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-2ce13a63] [WaitForUpdatesDone] Received callback

2016-01-20T20:12:37.840Z verbose vpxa[FFB39B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-2ce13a63] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 164281 to 164282 (at 164281)

2016-01-20T20:12:37.840Z verbose vpxa[FFB39B70] [Originator@6876 sub=vpxaTaskInfo opID=WFU-2ce13a63] [VpxaTaskInfoPublisher::PropertyChanged] Deferring completion update for vim.Task:haTask-ha-folder-vm-vim.Folder.createVm-977278

2016-01-20T20:12:37.840Z verbose vpxa[FFB39B70] [Originator@6876 sub=vpxaTaskInfo opID=WFU-2ce13a63] [VpxaTaskInfoPublisher::PropertyChanged] Number of deferred task updates: 1

2016-01-20T20:12:37.840Z verbose vpxa[FFB39B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-2ce13a63] [WaitForUpdatesDone] Found deferred task updates, will start CheckForUpdates() to get all related changes

2016-01-20T20:12:37.841Z verbose vpxa[FFB39B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-2ce13a63] [VpxaHalCnxHostagent::DoCheckForUpdates] CheckForUpdates() done; version sent: 164282, version received: (no update)

2016-01-20T20:12:37.841Z verbose vpxa[FFB39B70] [Originator@6876 sub=vpxaTaskInfo opID=WFU-2ce13a63] [VpxaTaskInfoPublisher::ProcessDeferredTasks] Updating completion status of 1 tasks

2016-01-20T20:12:37.841Z verbose vpxa[FFB39B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-2ce13a63] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2016-01-20T20:12:37.841Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxTaskInfo opID=SWI-76c05099] [TaskInfoChannel::GetTaskInfoHandleSuccess] task: haTask-ha-folder-vm-vim.Folder.createVm-977278 updated to version 2(known last version = 1)

2016-01-20T20:12:37.841Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxLro opID=SWI-76c05099] [VpxLRO] Dispatching Error Handler Functor for haTask-ha-folder-vm-vim.Folder.createVm-977278 which completed with an error from task-135960

2016-01-20T20:12:37.841Z verbose vpxa[FFB39B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-2ce13a63] [WaitForUpdatesDone] Completed callback

2016-01-20T20:12:37.841Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxLro opID=SWI-76c05099] [VpxLRO] Task task-135960 has been rescheduled

2016-01-20T20:12:37.842Z verbose vpxa[FFEADB70] [Originator@6876 sub=vpxLro opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-f2] [VpxLRO] Task task-135960 has been resumed

2016-01-20T20:12:37.842Z error vpxa[FFEADB70] [Originator@6876 sub=vpxaVmprov opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-f2] [CreateVmFailed] Received unexpected exception from host agent while creating VM: ffeacaa4

2016-01-20T20:12:37.842Z error vpxa[FFEADB70] [Originator@6876 sub=vpxLro opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-f2] [LroMainContinuation] Unexpected Exception: vim.fault.GenericVmConfigFault

2016-01-20T20:12:37.852Z verbose vpxa[FFEADB70] [Originator@6876 sub=vpxLro opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-f2] [LroMainContinuation] Backtrace:

-->

--> [backtrace begin] product: VMware ESX, version: 6.0.0, build: build-3029758, tag: vpxa

--> backtrace[00] libvmacore.so[0x003113C3]: Vmacore::System::Stacktrace::CaptureWork(unsigned int)

--> backtrace[01] libvmacore.so[0x001451A9]: Vmacore::System::SystemFactoryImpl::CreateQuickBacktrace(Vmacore::Ref<Vmacore::System::Backtrace>&)

--> backtrace[02] libvmacore.so[0x000EEE45]: Vmacore::Throwable::Throwable(std::string const&)

--> backtrace[03] libvmodlImpl.so[0x00BAF5C7]: Vim::Fault::GenericVmConfigFault::CreateException()

--> backtrace[04] vpxa[0x001F5F6E]

--> backtrace[05] vpxa[0x001F4C51]

--> backtrace[06] vpxa[0x0042D3C5]

--> backtrace[07] vpxa[0x00432415]: VpxLRO::LroMainContinuation(VpxLRO*, boost::function<bool ()> const&)

--> backtrace[08] vpxa[0x00422E6A]

--> backtrace[09] vpxa[0x0042D2C5]

--> backtrace[10] vpxa[0x00442299]: VpxLroList::ThreadMainEntry()

--> backtrace[11] vpxa[0x001E532B]

--> backtrace[12] libvmacore.so[0x00252070]

--> backtrace[13] libvmacore.so[0x0025627A]

--> backtrace[14] libvmacore.so[0x0025649C]

--> backtrace[15] libvmacore.so[0x0025DF7F]

--> backtrace[16] libvmacore.so[0x00252D68]

--> backtrace[17] libvmacore.so[0x00257603]

--> backtrace[18] libvmacore.so[0x0031B2CC]

--> backtrace[19] libpthread.so.0[0x00006D6A]

--> [backtrace end]

-->

2016-01-20T20:12:37.853Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-f2] RecordOp ASSIGN: info.state, task-135960. Applied change to temp map.

2016-01-20T20:12:37.853Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-f2] RecordOp ASSIGN: info.cancelable, task-135960. Applied change to temp map.

2016-01-20T20:12:37.853Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-f2] RecordOp ASSIGN: info.error, task-135960. Applied change to temp map.

2016-01-20T20:12:37.853Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-f2] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:37.853Z info vpxa[FFEADB70] [Originator@6876 sub=vpxLro opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-f2] [VpxLRO] -- FINISH task-135960

2016-01-20T20:12:37.853Z info vpxa[FFEADB70] [Originator@6876 sub=Default opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-f2] [VpxLRO] -- ERROR task-135960 -- vpxa -- vpxapi.VpxaService.createVm: vim.fault.GenericVmConfigFault:

--> Result:

--> (vim.fault.GenericVmConfigFault) {

--> faultCause = (vmodl.MethodFault) null,

--> faultMessage = (vmodl.LocalizableMessage) [

--> (vmodl.LocalizableMessage) {

--> key = "msg.dictionary.writefile.atomicUpdate",

--> arg = (vmodl.KeyAnyValue) [

--> (vmodl.KeyAnyValue) {

--> key = "1",

--> value = "/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmx"

--> },

--> (vmodl.KeyAnyValue) {

--> key = "2",

--> value = "13 (Permission denied)"

--> }

--> ],

--> message = "An error occurred while writing dictionary file "/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmx": 13 (Permission denied)."

--> }

--> ],

--> reason = "An error occurred while writing dictionary file "/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmx": 13 (Permission denied).",

--> msg = "An error occurred while writing dictionary file "/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmx": 13 (Permission denied)."

--> }

--> Args:

-->

--> Arg vmSpec:

--> (vim.vm.ConfigSpec) {

--> changeVersion = <unset>,

--> name = "Kyle Test",

--> version = "vmx-11",

--> uuid = "4225a3c1-2cd5-36fe-c1d0-3f254462a281",

--> instanceUuid = "50253deb-0b09-f655-e671-c4a94ef66881",

--> npivWorldWideNameType = <unset>,

--> npivDesiredNodeWwns = <unset>,

--> npivDesiredPortWwns = <unset>,

--> npivTemporaryDisabled = <unset>,

--> npivOnNonRdmDisks = <unset>,

--> npivWorldWideNameOp = <unset>,

--> locationId = <unset>,

--> guestId = "windows7Server64Guest",

--> alternateGuestName = <unset>,

--> annotation = <unset>,

--> files = (vim.vm.FileInfo) {

--> vmPathName = "[]/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmx",

--> snapshotDirectory = <unset>,

--> suspendDirectory = <unset>,

--> logDirectory = <unset>,

--> ftMetadataDirectory = <unset>

--> },

--> tools = (vim.vm.ToolsConfigInfo) {

--> toolsVersion = <unset>,

--> afterPowerOn = true,

--> afterResume = true,

--> beforeGuestStandby = true,

--> beforeGuestShutdown = true,

--> beforeGuestReboot = true,

--> toolsUpgradePolicy = <unset>,

--> pendingCustomization = <unset>,

--> syncTimeWithHost = <unset>,

--> lastInstallInfo = (vim.vm.ToolsConfigInfo.ToolsLastInstallInfo) null,

--> upgradeRebootPredict = <unset>

--> },

--> flags = (vim.vm.FlagInfo) {

--> disableAcceleration = <unset>,

--> enableLogging = <unset>,

--> useToe = <unset>,

--> runWithDebugInfo = <unset>,

--> monitorType = <unset>,

--> htSharing = <unset>,

--> snapshotDisabled = <unset>,

--> snapshotLocked = <unset>,

--> diskUuidEnabled = true,

--> virtualMmuUsage = "automatic",

--> virtualExecUsage = "hvAuto",

--> snapshotPowerOffBehavior = "powerOff",

--> recordReplayEnabled = <unset>,

--> faultToleranceType = <unset>

--> },

--> consolePreferences = (vim.vm.ConsolePreferences) null,

--> powerOpInfo = (vim.vm.DefaultPowerOpInfo) {

--> powerOffType = "preset",

--> suspendType = "preset",

--> resetType = "preset",

--> defaultPowerOffType = <unset>,

--> defaultSuspendType = <unset>,

--> defaultResetType = <unset>,

--> standbyAction = "checkpoint"

--> },

--> numCPUs = 1,

--> numCoresPerSocket = 1,

--> memoryMB = 4096,

--> memoryHotAddEnabled = <unset>,

--> cpuHotAddEnabled = <unset>,

--> cpuHotRemoveEnabled = <unset>,

--> virtualICH7MPresent = <unset>,

--> virtualSMCPresent = <unset>,

--> deviceChange = (vim.vm.device.VirtualDeviceSpec) [

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = "create",

--> device = (vim.vm.device.VirtualDisk) {

--> key = -136,

--> deviceInfo = (vim.Description) {

--> label = "New Hard disk",

--> summary = ""

--> },

--> backing = (vim.vm.device.VirtualDisk.FlatVer2BackingInfo) {

--> fileName = "[]/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmdk",

--> datastore = <unset>,

--> backingObjectId = <unset>,

--> diskMode = "persistent",

--> split = false,

--> writeThrough = false,

--> thinProvisioned = true,

--> eagerlyScrub = false,

--> uuid = <unset>,

--> contentId = <unset>,

--> changeId = <unset>,

--> parent = (vim.vm.device.VirtualDisk.FlatVer2BackingInfo) null,

--> deltaDiskFormat = <unset>,

--> digestEnabled = <unset>,

--> deltaGrainSize = <unset>,

--> deltaDiskFormatVariant = <unset>,

--> sharing = <unset>

--> },

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = -135,

--> unitNumber = 0,

--> capacityInKB = 41943040,

--> capacityInBytes = <unset>,

--> shares = (vim.SharesInfo) {

--> shares = 1000,

--> level = "normal"

--> },

--> storageIOAllocation = (vim.StorageResourceManager.IOAllocationInfo) {

--> limit = -1,

--> shares = (vim.SharesInfo) {

--> shares = 1000,

--> level = "normal"

--> },

--> reservation = <unset>

--> },

--> diskObjectId = <unset>,

--> vFlashCacheConfigInfo = (vim.vm.device.VirtualDisk.VFlashCacheConfigInfo) null,

--> },

--> profile = (vim.vm.ProfileSpec) [

--> (vim.vm.EmptyProfileSpec) {

--> }

--> ]

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualLsiLogicSASController) {

--> key = -135,

--> deviceInfo = (vim.Description) {

--> label = "New SCSI controller",

--> summary = ""

--> },

--> backing = (vim.vm.device.VirtualDevice.BackingInfo) null,

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = <unset>,

--> unitNumber = <unset>,

--> busNumber = 0,

--> hotAddRemove = <unset>,

--> sharedBus = "noSharing",

--> scsiCtlrUnitNumber = <unset>,

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualE1000) {

--> key = -137,

--> deviceInfo = (vim.Description) {

--> label = "New Network",

--> summary = ""

--> },

--> backing = (vim.vm.device.VirtualEthernetCard.NetworkBackingInfo) {

--> deviceName = "Production Network",

--> useAutoDetect = <unset>,

--> network = <unset>,

--> inPassthroughMode = <unset>

--> },

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) {

--> startConnected = true,

--> allowGuestControl = true,

--> connected = true,

--> status = "untried"

--> },

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = <unset>,

--> unitNumber = <unset>,

--> addressType = "Assigned",

--> macAddress = "00:50:56:a5:67:0d",

--> wakeOnLanEnabled = true,

--> resourceAllocation = (vim.vm.device.VirtualEthernetCard.ResourceAllocation) null,

--> externalId = <unset>,

--> uptCompatibilityEnabled = <unset>,

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualCdrom) {

--> key = -133,

--> deviceInfo = (vim.Description) {

--> label = "New CD/DVD Drive",

--> summary = ""

--> },

--> backing = (vim.vm.device.VirtualCdrom.RemotePassthroughBackingInfo) {

--> deviceName = "",

--> useAutoDetect = <unset>,

--> exclusive = false

--> },

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) {

--> startConnected = false,

--> allowGuestControl = true,

--> connected = false,

--> status = <unset>

--> },

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = -132,

--> unitNumber = 0

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualFloppy) {

--> key = -134,

--> deviceInfo = (vim.Description) {

--> label = "New Floppy drive",

--> summary = ""

--> },

--> backing = (vim.vm.device.VirtualFloppy.RemoteDeviceBackingInfo) {

--> deviceName = "",

--> useAutoDetect = <unset>

--> },

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) {

--> startConnected = false,

--> allowGuestControl = true,

--> connected = false,

--> status = <unset>

--> },

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = <unset>,

--> unitNumber = <unset>

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualVideoCard) {

--> key = 500,

--> deviceInfo = (vim.Description) {

--> label = "Video card ",

--> summary = ""

--> },

--> backing = (vim.vm.device.VirtualDevice.BackingInfo) null,

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = 100,

--> unitNumber = 0,

--> videoRamSizeInKB = 8192,

--> numDisplays = 1,

--> useAutoDetect = false,

--> enable3DSupport = false,

--> enableMPTSupport = <unset>,

--> use3dRenderer = <unset>,

--> graphicsMemorySizeInKB = 262144

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualKeyboard) {

--> key = 600,

--> deviceInfo = (vim.Description) {

--> label = "Keyboard ",

--> summary = ""

--> },

--> backing = (vim.vm.device.VirtualDevice.BackingInfo) null,

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = 300,

--> unitNumber = 0

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualIDEController) {

--> key = 200,

--> deviceInfo = (vim.Description) {

--> label = "IDE 0",

--> summary = "0"

--> },

--> backing = (vim.vm.device.VirtualDevice.BackingInfo) null,

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = <unset>,

--> unitNumber = <unset>,

--> busNumber = 0,

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualVMCIDevice) {

--> key = 12000,

--> deviceInfo = (vim.Description) {

--> label = "VMCI device",

--> summary = "Device on the virtual machine PCI bus that provides support for the virtual machine communication interface"

--> },

--> backing = (vim.vm.device.VirtualDevice.BackingInfo) null,

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = 100,

--> unitNumber = 17,

--> id = <unset>,

--> allowUnrestrictedCommunication = false,

--> filterEnable = <unset>,

--> filterInfo = (vim.vm.device.VirtualVMCIDevice.FilterInfo) null

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualAHCIController) {

--> key = -132,

--> deviceInfo = (vim.Description) {

--> label = "New SATA Controller",

--> summary = ""

--> },

--> backing = (vim.vm.device.VirtualDevice.BackingInfo) null,

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = <unset>,

--> unitNumber = <unset>,

--> busNumber = 0,

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualPointingDevice) {

--> key = 700,

--> deviceInfo = (vim.Description) {

--> label = "Pointing device",

--> summary = "Pointing device; Device"

--> },

--> backing = (vim.vm.device.VirtualPointingDevice.DeviceBackingInfo) {

--> deviceName = "",

--> useAutoDetect = false,

--> hostPointingDevice = "autodetect"

--> },

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = 300,

--> unitNumber = 1

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualSIOController) {

--> key = 400,

--> deviceInfo = (vim.Description) {

--> label = "SIO controller 0",

--> summary = "0"

--> },

--> backing = (vim.vm.device.VirtualDevice.BackingInfo) null,

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = <unset>,

--> unitNumber = <unset>,

--> busNumber = 0,

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualPCIController) {

--> key = 100,

--> deviceInfo = (vim.Description) {

--> label = "PCI controller 0",

--> summary = "0"

--> },

--> backing = (vim.vm.device.VirtualDevice.BackingInfo) null,

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = <unset>,

--> unitNumber = <unset>,

--> busNumber = 0,

--> device = (int) [

--> 500,

--> 12000

--> ]

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualPS2Controller) {

--> key = 300,

--> deviceInfo = (vim.Description) {

--> label = "PS2 controller 0",

--> summary = "0"

--> },

--> backing = (vim.vm.device.VirtualDevice.BackingInfo) null,

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = <unset>,

--> unitNumber = <unset>,

--> busNumber = 0,

--> device = (int) [

--> 600,

--> 700

--> ]

--> },

--> },

--> (vim.vm.device.VirtualDeviceSpec) {

--> operation = "add",

--> fileOperation = <unset>,

--> device = (vim.vm.device.VirtualIDEController) {

--> key = 201,

--> deviceInfo = (vim.Description) {

--> label = "IDE 1",

--> summary = "1"

--> },

--> backing = (vim.vm.device.VirtualDevice.BackingInfo) null,

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = <unset>,

--> unitNumber = <unset>,

--> busNumber = 1,

--> },

--> }

--> ],

--> cpuAllocation = (vim.ResourceAllocationInfo) {

--> reservation = 0,

--> expandableReservation = <unset>,

--> limit = -1,

--> shares = (vim.SharesInfo) {

--> shares = 0,

--> level = "normal"

--> },

--> overheadLimit = <unset>

--> },

--> memoryAllocation = (vim.ResourceAllocationInfo) {

--> reservation = 0,

--> expandableReservation = <unset>,

--> limit = -1,

--> shares = (vim.SharesInfo) {

--> shares = 0,

--> level = "normal"

--> },

--> overheadLimit = <unset>

--> },

--> latencySensitivity = (vim.LatencySensitivity) null,

--> cpuAffinity = (vim.vm.AffinityInfo) {

--> },

--> memoryAffinity = (vim.vm.AffinityInfo) null,

--> networkShaper = (vim.vm.NetworkShaperInfo) null,

--> swapPlacement = "inherit",

--> swapDirectory = <unset>,

--> preserveSwapOnPowerOff = <unset>,

--> bootOptions = (vim.vm.BootOptions) null,

--> vAppConfig = (vim.vApp.VmConfigSpec) null,

--> ftInfo = (vim.vm.FaultToleranceConfigInfo) null,

--> repConfig = (vim.vm.ReplicationConfigSpec) null,

--> vAppConfigRemoved = <unset>,

--> vAssertsEnabled = <unset>,

--> changeTrackingEnabled = <unset>,

--> firmware = "bios",

--> maxMksConnections = <unset>,

--> guestAutoLockEnabled = <unset>,

--> managedBy = (vim.ext.ManagedByInfo) null,

--> memoryReservationLockedToMax = <unset>,

--> nestedHVEnabled = <unset>,

--> vPMCEnabled = <unset>,

--> scheduledHardwareUpgradeInfo = (vim.vm.ScheduledHardwareUpgradeInfo) null,

--> vmProfile = (vim.vm.ProfileSpec) [

--> (vim.vm.EmptyProfileSpec) {

--> }

--> ],

--> messageBusQueuePattern = <unset>,

--> messageBusTunnelEnabled = <unset>,

--> }

--> Arg pool:

--> 'vim.ResourcePool:resgroup-8'

--> Arg doRegister:

--> true

--> Arg isTemplate:

--> false

2016-01-20T20:12:37.875Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider] RecordOp ASSIGN: info.completeTime, task-135960. Applied change to temp map.

2016-01-20T20:12:37.875Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:37.896Z info vpxa[FFAD6A60] [Originator@6876 sub=vpxLro opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-da] [VpxLRO] -- BEGIN task-internal-135961 -- vpxa -- vpxapi.VpxaService.unregisterVmByCfgPath -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:12:37.896Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaMoVm opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-da] [VpxaMoVm] Looking up vm with config file ds:///vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmx

2016-01-20T20:12:37.896Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaDatastoreContext opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-da] [VpxaDatastoreContext] Resolved URL ds:///vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmx to localPath /vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmx

2016-01-20T20:12:37.896Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaVmomi opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-da] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:12:37.896Z info vpxa[FFAD6A60] [Originator@6876 sub=vpxLro opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-da] [VpxLRO] -- FINISH task-internal-135961

2016-01-20T20:12:37.898Z verbose vpxa[FFEEFB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] RecordOp ASSIGN: info.reason, task-135962. Applied change to temp map.

2016-01-20T20:12:37.898Z verbose vpxa[FFEEFB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:37.898Z verbose vpxa[FFEEFB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] RecordOp ADD: recentTask["task-135962"], vpxaTaskManager. Sent notification immediately.

2016-01-20T20:12:37.898Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider] RecordOp ASSIGN: info.startTime, task-135962. Applied change to temp map.

2016-01-20T20:12:37.899Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:37.899Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] RecordOp ASSIGN: info.state, task-135962. Applied change to temp map.

2016-01-20T20:12:37.899Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] RecordOp ASSIGN: info.cancelable, task-135962. Applied change to temp map.

2016-01-20T20:12:37.899Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:37.899Z info vpxa[FFEADB70] [Originator@6876 sub=vpxLro opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] [VpxLRO] -- BEGIN task-135962 -- vpxa -- vpxapi.VpxaService.destroyVm -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:12:37.902Z verbose vpxa[FFEEFB70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-691d9758] [WaitForUpdatesDone] Received callback

2016-01-20T20:12:37.902Z verbose vpxa[FFEEFB70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-691d9758] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 164282 to 164283 (at 164282)

2016-01-20T20:12:37.902Z verbose vpxa[FFEEFB70] [Originator@6876 sub=vpxaTaskInfo opID=WFU-691d9758] [VpxaTaskInfoPublisher::PropertyChanged] Number of deferred task updates: 0

2016-01-20T20:12:37.902Z verbose vpxa[FFEEFB70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-691d9758] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2016-01-20T20:12:37.902Z verbose vpxa[FFB39B70] [Originator@6876 sub=vpxTaskInfo opID=SWI-15bb4852] [TaskInfoChannel::GetTaskInfoHandleSuccess] task: haTask--vim.host.LowLevelProvisioningManager.deleteVm-977284 updated to version 1(known last version = 0)

2016-01-20T20:12:37.902Z verbose vpxa[FFEEFB70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-691d9758] [WaitForUpdatesDone] Completed callback

2016-01-20T20:12:37.904Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7b19715a] [WaitForUpdatesDone] Received callback

2016-01-20T20:12:37.904Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7b19715a] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 164283 to 164284 (at 164283)

2016-01-20T20:12:37.904Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaTaskInfo opID=WFU-7b19715a] [VpxaTaskInfoPublisher::PropertyChanged] Deferring completion update for vim.Task:haTask--vim.host.LowLevelProvisioningManager.deleteVm-977284

2016-01-20T20:12:37.904Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaTaskInfo opID=WFU-7b19715a] [VpxaTaskInfoPublisher::PropertyChanged] Number of deferred task updates: 1

2016-01-20T20:12:37.904Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7b19715a] [WaitForUpdatesDone] Found deferred task updates, will start CheckForUpdates() to get all related changes

2016-01-20T20:12:37.905Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7b19715a] [VpxaHalCnxHostagent::DoCheckForUpdates] CheckForUpdates() done; version sent: 164284, version received: (no update)

2016-01-20T20:12:37.905Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaTaskInfo opID=WFU-7b19715a] [VpxaTaskInfoPublisher::ProcessDeferredTasks] Updating completion status of 1 tasks

2016-01-20T20:12:37.905Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7b19715a] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2016-01-20T20:12:37.905Z verbose vpxa[FFEEFB70] [Originator@6876 sub=vpxTaskInfo opID=SWI-43610ad9] [TaskInfoChannel::GetTaskInfoHandleSuccess] task: haTask--vim.host.LowLevelProvisioningManager.deleteVm-977284 updated to version 2(known last version = 1)

2016-01-20T20:12:37.905Z verbose vpxa[FFEEFB70] [Originator@6876 sub=vpxLro opID=SWI-43610ad9] [VpxLRO] Dispatching Error Handler Functor for haTask--vim.host.LowLevelProvisioningManager.deleteVm-977284 which completed with an error from task-135962

2016-01-20T20:12:37.905Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-7b19715a] [WaitForUpdatesDone] Completed callback

2016-01-20T20:12:37.914Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] RecordOp ASSIGN: info.state, task-135962. Applied change to temp map.

2016-01-20T20:12:37.914Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] RecordOp ASSIGN: info.cancelable, task-135962. Applied change to temp map.

2016-01-20T20:12:37.915Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] RecordOp ASSIGN: info.error, task-135962. Applied change to temp map.

2016-01-20T20:12:37.915Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:37.915Z info vpxa[FFEADB70] [Originator@6876 sub=vpxLro opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] [VpxLRO] -- FINISH task-135962

2016-01-20T20:12:37.915Z info vpxa[FFEADB70] [Originator@6876 sub=Default opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-e8] [VpxLRO] -- ERROR task-135962 -- vpxa -- vpxapi.VpxaService.destroyVm: vmodl.fault.InvalidArgument:

--> Result:

--> (vmodl.fault.InvalidArgument) {

--> faultCause = (vmodl.MethodFault) null,

--> invalidProperty = "ConfigSpec.files.vmPathName",

--> msg = "A specified parameter was not correct: ConfigSpec.files.vmPathName"

--> }

--> Args:

-->

--> Arg vmConfigInfo:

--> (vim.vm.ConfigInfo) {

--> changeVersion = "",

--> modified = "1970-01-01T00:00:00Z",

--> name = "Kyle Test",

--> guestFullName = "",

--> version = "",

--> uuid = "",

--> instanceUuid = <unset>,

--> npivWorldWideNameType = <unset>,

--> npivDesiredNodeWwns = <unset>,

--> npivDesiredPortWwns = <unset>,

--> npivTemporaryDisabled = <unset>,

--> npivOnNonRdmDisks = <unset>,

--> locationId = "",

--> template = false,

--> guestId = "",

--> alternateGuestName = "",

--> annotation = <unset>,

--> files = (vim.vm.FileInfo) {

--> vmPathName = "[]/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmx",

--> snapshotDirectory = <unset>,

--> suspendDirectory = <unset>,

--> logDirectory = <unset>,

--> ftMetadataDirectory = <unset>

--> },

--> tools = (vim.vm.ToolsConfigInfo) null,

--> flags = (vim.vm.FlagInfo) {

--> disableAcceleration = <unset>,

--> enableLogging = <unset>,

--> useToe = <unset>,

--> runWithDebugInfo = <unset>,

--> monitorType = <unset>,

--> htSharing = <unset>,

--> snapshotDisabled = <unset>,

--> snapshotLocked = <unset>,

--> diskUuidEnabled = <unset>,

--> virtualMmuUsage = <unset>,

--> virtualExecUsage = <unset>,

--> snapshotPowerOffBehavior = <unset>,

--> recordReplayEnabled = <unset>,

--> faultToleranceType = <unset>

--> },

--> consolePreferences = (vim.vm.ConsolePreferences) null,

--> defaultPowerOps = (vim.vm.DefaultPowerOpInfo) {

--> powerOffType = <unset>,

--> suspendType = <unset>,

--> resetType = <unset>,

--> defaultPowerOffType = <unset>,

--> defaultSuspendType = <unset>,

--> defaultResetType = <unset>,

--> standbyAction = <unset>

--> },

--> hardware = (vim.vm.VirtualHardware) {

--> numCPU = 172827328,

--> numCoresPerSocket = <unset>,

--> memoryMB = 0,

--> virtualICH7MPresent = <unset>,

--> virtualSMCPresent = <unset>,

--> device = (vim.vm.device.VirtualDevice) [

--> (vim.vm.device.VirtualDisk) {

--> key = -136,

--> deviceInfo = (vim.Description) {

--> label = "New Hard disk",

--> summary = ""

--> },

--> backing = (vim.vm.device.VirtualDisk.FlatVer2BackingInfo) {

--> fileName = "[]/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test/Kyle Test.vmdk",

--> datastore = <unset>,

--> backingObjectId = <unset>,

--> diskMode = "persistent",

--> split = false,

--> writeThrough = false,

--> thinProvisioned = true,

--> eagerlyScrub = false,

--> uuid = <unset>,

--> contentId = <unset>,

--> changeId = <unset>,

--> parent = (vim.vm.device.VirtualDisk.FlatVer2BackingInfo) null,

--> deltaDiskFormat = <unset>,

--> digestEnabled = <unset>,

--> deltaGrainSize = <unset>,

--> deltaDiskFormatVariant = <unset>,

--> sharing = <unset>

--> },

--> connectable = (vim.vm.device.VirtualDevice.ConnectInfo) null,

--> slotInfo = (vim.vm.device.VirtualDevice.BusSlotInfo) null,

--> controllerKey = -135,

--> unitNumber = 0,

--> capacityInKB = 41943040,

--> capacityInBytes = <unset>,

--> shares = (vim.SharesInfo) {

--> shares = 1000,

--> level = "normal"

--> },

--> storageIOAllocation = (vim.StorageResourceManager.IOAllocationInfo) {

--> limit = -1,

--> shares = (vim.SharesInfo) {

--> shares = 1000,

--> level = "normal"

--> },

--> reservation = <unset>

--> },

--> diskObjectId = <unset>,

--> vFlashCacheConfigInfo = (vim.vm.device.VirtualDisk.VFlashCacheConfigInfo) null,

--> }

--> ]

--> },

--> cpuAllocation = (vim.ResourceAllocationInfo) null,

--> memoryAllocation = (vim.ResourceAllocationInfo) null,

--> latencySensitivity = (vim.LatencySensitivity) null,

--> memoryHotAddEnabled = <unset>,

--> cpuHotAddEnabled = <unset>,

--> cpuHotRemoveEnabled = <unset>,

--> hotPlugMemoryLimit = <unset>,

--> hotPlugMemoryIncrementSize = <unset>,

--> cpuAffinity = (vim.vm.AffinityInfo) null,

--> memoryAffinity = (vim.vm.AffinityInfo) null,

--> networkShaper = (vim.vm.NetworkShaperInfo) null,

--> swapPlacement = <unset>,

--> swapDirectory = <unset>,

--> preserveSwapOnPowerOff = <unset>,

--> bootOptions = (vim.vm.BootOptions) null,

--> ftInfo = (vim.vm.FaultToleranceConfigInfo) null,

--> repConfig = (vim.vm.ReplicationConfigSpec) null,

--> vAppConfig = (vim.vApp.VmConfigInfo) null,

--> vAssertsEnabled = <unset>,

--> changeTrackingEnabled = <unset>,

--> firmware = <unset>,

--> maxMksConnections = <unset>,

--> guestAutoLockEnabled = <unset>,

--> managedBy = (vim.ext.ManagedByInfo) null,

--> memoryReservationLockedToMax = <unset>,

--> initialOverhead = (vim.vm.ConfigInfo.OverheadInfo) null,

--> nestedHVEnabled = <unset>,

--> vPMCEnabled = <unset>,

--> scheduledHardwareUpgradeInfo = (vim.vm.ScheduledHardwareUpgradeInfo) null,

--> forkConfigInfo = (vim.vm.ForkConfigInfo) null,

--> vFlashCacheReservation = <unset>,

--> vmxConfigChecksum = <unset>,

--> messageBusQueuePattern = <unset>,

--> messageBusTunnelEnabled = <unset>,

--> vmStorageObjectId = <unset>,

--> swapStorageObjectId = <unset>,

--> }

--> Arg vmid:

-->

2016-01-20T20:12:37.915Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider] RecordOp ASSIGN: info.completeTime, task-135962. Applied change to temp map.

2016-01-20T20:12:37.916Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:37.948Z info vpxa[FFF10B70] [Originator@6876 sub=vpxLro opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-25] [VpxLRO] -- BEGIN task-internal-135963 -- vpxa -- vpxapi.VpxaService.unregisterVm -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:12:37.948Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxaVmprov opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-25] unregister vm

2016-01-20T20:12:37.948Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxaVmprov opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-25] remove 1 number of files

2016-01-20T20:12:37.948Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxaDatastoreContext opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-25] [VpxaDatastoreContext] Resolved URL ds:///vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test to localPath /vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test

2016-01-20T20:12:37.948Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxaDatastoreContext opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-25] [VpxaDatastoreContext] Resolved URL /vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test to localPath /vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Kyle Test

2016-01-20T20:12:37.948Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxaDatastoreContext opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-25] [Url] Resolved localPath /vmfs/volumes/7bc914c3-38077c80-0000-000000000000/ to URL ds:///vmfs/volumes/7bc914c3-38077c80-0000-000000000000/

2016-01-20T20:12:37.948Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxaVmomi opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-25] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:12:37.948Z info vpxa[FFF10B70] [Originator@6876 sub=vpxLro opID=be8312a5-2d3a-484e-acfc-bdfa646f7976-1321-ngc-f7-45-25] [VpxLRO] -- FINISH task-internal-135963

2016-01-20T20:12:39.959Z verbose vpxa[FFF10B70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] RecordOp ASSIGN: info.reason, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:39.959Z verbose vpxa[FFF10B70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:39.960Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider] RecordOp ASSIGN: info.startTime, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:39.960Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:39.960Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] RecordOp ASSIGN: info.state, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:39.960Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] RecordOp ASSIGN: info.cancelable, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:39.960Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:39.960Z info vpxa[FFEADB70] [Originator@6876 sub=vpxLro opID=HB-host-10@36206-113afdae-30] [VpxLRO] -- BEGIN session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757 -- vpxa -- vpxapi.VpxaService.retrieveChanges -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:12:39.960Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [1+] VpxaMoService::GetChanges

2016-01-20T20:12:39.960Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxLro opID=HB-host-10@36206-113afdae-30-SWI-318c5400] [VpxLroList::ForgetTask] Removed vim.Task:session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52f6b040-93ca-1951-32a7-123f0afae70f from _completed

2016-01-20T20:12:39.960Z info vpxa[FFF10B70] [Originator@6876 sub=vpxLro opID=HB-host-10@36206-113afdae-30-SWI-318c5400] [VpxLroList::ForgetTask] Unregistering vim.Task:session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52f6b040-93ca-1951-32a7-123f0afae70f

2016-01-20T20:12:39.962Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxaHalCnxHostagent opID=HB-host-10@36206-113afdae-30] [VpxaHalCnxHostagent::DoCheckForUpdates] CheckForUpdates() done; version sent: 164284, version received: (no update)

2016-01-20T20:12:39.962Z verbose vpxa[FFEADB70] [Originator@6876 sub=vpxaMoService opID=HB-host-10@36206-113afdae-30] [VpxaMoService] GetChanges: 36197 -> 36206

2016-01-20T20:12:39.962Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [2+] VpxaStatsMetadata::PrepareStatsChanges

2016-01-20T20:12:40.000Z verbose vpxa[FFEADB70] [Originator@6876 sub=vpxaStatsMetadata opID=HB-host-10@36206-113afdae-30] [VpxaStatsMetadata] Prior to refilling translations (422, 422)

2016-01-20T20:12:40.001Z verbose vpxa[FFEADB70] [Originator@6876 sub=vpxaStatsMetadata opID=HB-host-10@36206-113afdae-30] [VpxaStatsMetadata] Refilled translations (422, 422)

2016-01-20T20:12:40.001Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [2-] VpxaStatsMetadata::PrepareStatsChanges (took 39 ms)

2016-01-20T20:12:40.001Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [2+] VpxdDatastore::PrepareChanges

2016-01-20T20:12:40.001Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [2-] VpxdDatastore::PrepareChanges (took 0 ms)

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [2+] VpxaMoService::PrepareHostChanges

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=vpxaMoService opID=HB-host-10@36206-113afdae-30] [VpxaMoService] host changes include changed properties []

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [2-] VpxaMoService::PrepareHostChanges (took 0 ms)

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [2+] VpxaMoService::PrepareVmChanges

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] RecordOp ASSIGN: info.progress, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] RecordOp ASSIGN: info.progress, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] RecordOp ASSIGN: info.progress, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [2-] VpxaMoService::PrepareVmChanges (took 0 ms)

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [2+] VpxaDrs::PrepareChanges

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [2-] VpxaDrs::PrepareChanges (took 0 ms)

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=VpxProfiler opID=HB-host-10@36206-113afdae-30] [1-] VpxaMoService::GetChanges (took 42 ms)

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=vpxaVmomi opID=HB-host-10@36206-113afdae-30] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] RecordOp ASSIGN: info, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] RecordOp ASSIGN: info.state, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] RecordOp ASSIGN: info.cancelable, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] RecordOp ASSIGN: info.result, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider opID=HB-host-10@36206-113afdae-30] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:40.002Z info vpxa[FFEADB70] [Originator@6876 sub=vpxLro opID=HB-host-10@36206-113afdae-30] [VpxLRO] -- FINISH session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider] RecordOp ASSIGN: info.completeTime, session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]52ac06ee-29e2-ecf0-acaa-246c9e0bd757. Applied change to temp map.

2016-01-20T20:12:40.002Z verbose vpxa[FFEADB70] [Originator@6876 sub=PropertyProvider] [CommitChangesAndNotify] Updating cached values

2016-01-20T20:12:40.006Z info vpxa[FFB39B70] [Originator@6876 sub=vpxLro opID=HB-host-10@36206-113afdae-61] [VpxLRO] -- BEGIN task-internal-135964 -- session[520cbe98-ade2-3ed7-9aa9-de30703fd6ce]5250b46a-103a-c405-6aab-49b3cbf72e3f -- vmodl.query.PropertyCollector.Filter.destroy -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:12:40.006Z verbose vpxa[FFB39B70] [Originator@6876 sub=vpxaVmomi opID=HB-host-10@36206-113afdae-61] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:12:40.006Z info vpxa[FFB39B70] [Originator@6876 sub=vpxLro opID=HB-host-10@36206-113afdae-61] [VpxLRO] -- FINISH task-internal-135964

2016-01-20T20:12:47.808Z verbose vpxa[FFAD6A60] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:13:04.645Z info vpxa[FFEEFB70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-5c] [VpxLRO] -- BEGIN task-internal-135965 -- vpxa -- vpxapi.VpxaService.fetchQuickStats -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:13:04.646Z verbose vpxa[FFEEFB70] [Originator@6876 sub=vpxaVmomi opID=PollQuickStatsLoop-606df6c8-5c] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:13:04.646Z info vpxa[FFEEFB70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-5c] [VpxLRO] -- FINISH task-internal-135965

2016-01-20T20:13:07.808Z verbose vpxa[FFAD6A60] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:13:27.812Z verbose vpxa[FFAD6A60] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:13:47.814Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:14:04.647Z info vpxa[FFF10B70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-8e] [VpxLRO] -- BEGIN task-internal-135966 -- vpxa -- vpxapi.VpxaService.fetchQuickStats -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:14:04.648Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxaVmomi opID=PollQuickStatsLoop-606df6c8-8e] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:14:04.648Z info vpxa[FFF10B70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-8e] [VpxLRO] -- FINISH task-internal-135966

2016-01-20T20:14:07.816Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:14:27.819Z verbose vpxa[FFAD6A60] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:14:47.818Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:15:04.648Z info vpxa[FFAD6A60] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-9c] [VpxLRO] -- BEGIN task-internal-135967 -- vpxa -- vpxapi.VpxaService.fetchQuickStats -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:15:04.649Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaVmomi opID=PollQuickStatsLoop-606df6c8-9c] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:15:04.649Z info vpxa[FFAD6A60] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-9c] [VpxLRO] -- FINISH task-internal-135967

2016-01-20T20:15:07.819Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:15:13.956Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-3b74ae24] [WaitForUpdatesDone] Received callback

2016-01-20T20:15:13.956Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-3b74ae24] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 164284 to 164285 (at 164284)

2016-01-20T20:15:13.956Z verbose vpxa[FFF10B70] [Originator@6876 sub=halservices opID=WFU-3b74ae24] [VpxaHalServices] HostChanged Event Fired, properties changed [runtime.healthSystemRuntime]

2016-01-20T20:15:13.957Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxaInvtHost opID=WFU-3b74ae24] [HostChanged] Found update for tracked MoRef vim.HostSystem:ha-host

2016-01-20T20:15:13.957Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-3b74ae24] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2016-01-20T20:15:13.957Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-3b74ae24] [WaitForUpdatesDone] Completed callback

2016-01-20T20:15:27.824Z verbose vpxa[FFF10B70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:15:47.824Z verbose vpxa[FFAD6A60] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:16:04.648Z info vpxa[FFF10B70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-fa] [VpxLRO] -- BEGIN task-internal-135968 -- vpxa -- vpxapi.VpxaService.fetchQuickStats -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:16:04.649Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxaVmomi opID=PollQuickStatsLoop-606df6c8-fa] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:16:04.649Z info vpxa[FFF10B70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-fa] [VpxLRO] -- FINISH task-internal-135968

2016-01-20T20:16:07.827Z verbose vpxa[FFF10B70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:16:22.109Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxProfiler] [1+] CheckEnvBrowserChanges

2016-01-20T20:16:22.131Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxProfiler] [1-] CheckEnvBrowserChanges (took 22 ms)

2016-01-20T20:16:27.828Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:16:43.798Z info vpxa[FFAD6A60] [Originator@6876 sub=vpxLro opID=39424e63-39] [VpxLRO] -- BEGIN task-internal-135969 -- host -- vim.HostSystem.acquireCimServicesTicket -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:16:43.802Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaVmomi opID=39424e63-39] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:16:43.802Z info vpxa[FFAD6A60] [Originator@6876 sub=vpxLro opID=39424e63-39] [VpxLRO] -- FINISH task-internal-135969

2016-01-20T20:16:43.802Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-1e4d3eb3] [WaitForUpdatesDone] Received callback

2016-01-20T20:16:43.802Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-1e4d3eb3] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 164285 to 164286 (at 164285)

2016-01-20T20:16:43.802Z verbose vpxa[FFF10B70] [Originator@6876 sub=vpxaTaskInfo opID=WFU-1e4d3eb3] [VpxaTaskInfoPublisher::PropertyChanged] Number of deferred task updates: 0

2016-01-20T20:16:43.802Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-1e4d3eb3] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2016-01-20T20:16:43.803Z verbose vpxa[FFF10B70] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-1e4d3eb3] [WaitForUpdatesDone] Completed callback

2016-01-20T20:16:43.805Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-614f694f] [WaitForUpdatesDone] Received callback

2016-01-20T20:16:43.805Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-614f694f] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 164286 to 164287 (at 164286)

2016-01-20T20:16:43.805Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaTaskInfo opID=WFU-614f694f] [VpxaTaskInfoPublisher::PropertyChanged] Number of deferred task updates: 0

2016-01-20T20:16:43.805Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-614f694f] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2016-01-20T20:16:43.805Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-614f694f] [WaitForUpdatesDone] Completed callback

2016-01-20T20:16:47.828Z verbose vpxa[FFAD6A60] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:16:57.024Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-248af372] [WaitForUpdatesDone] Received callback

2016-01-20T20:16:57.024Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-248af372] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 164287 to 164288 (at 164287)

2016-01-20T20:16:57.024Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaTaskInfo opID=WFU-248af372] [VpxaTaskInfoPublisher::PropertyChanged] Number of deferred task updates: 0

2016-01-20T20:16:57.024Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-248af372] [WaitForUpdatesDone] Starting next WaitForUpdates() call to hostd

2016-01-20T20:16:57.025Z verbose vpxa[FFAD6A60] [Originator@6876 sub=VpxaHalCnxHostagent opID=WFU-248af372] [WaitForUpdatesDone] Completed callback

2016-01-20T20:17:04.649Z verbose vpxa[FFF10B70] [Originator@6876 sub=SoapAdapter] Responded to service state request

2016-01-20T20:17:04.649Z info vpxa[FFEEFB70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-1c] [VpxLRO] -- BEGIN task-internal-135970 -- vpxa -- vpxapi.VpxaService.fetchQuickStats -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:17:04.650Z verbose vpxa[FFEEFB70] [Originator@6876 sub=vpxaVmomi opID=PollQuickStatsLoop-606df6c8-1c] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:17:04.650Z info vpxa[FFEEFB70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-1c] [VpxLRO] -- FINISH task-internal-135970

2016-01-20T20:17:07.830Z verbose vpxa[FFAD6A60] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:17:27.833Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:17:47.835Z verbose vpxa[FFF10B70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:18:04.650Z info vpxa[FFAD6A60] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-38] [VpxLRO] -- BEGIN task-internal-135971 -- vpxa -- vpxapi.VpxaService.fetchQuickStats -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:18:04.652Z verbose vpxa[FFAD6A60] [Originator@6876 sub=vpxaVmomi opID=PollQuickStatsLoop-606df6c8-38] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:18:04.652Z info vpxa[FFAD6A60] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-38] [VpxLRO] -- FINISH task-internal-135971

2016-01-20T20:18:07.836Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:18:27.838Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:18:47.838Z verbose vpxa[FFB39B70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:18:51.572Z verbose vpxa[FFEEFB70] [Originator@6876 sub=HttpConnectionPool-000000] [RemoveConnection] Connection removed; cnx: <io_obj p:0x1f4d050c, h:-1, <TCP '0.0.0.0:0'>, <TCP '127.0.0.1:8307'>>; pooled: 2

2016-01-20T20:19:04.652Z info vpxa[FFEEFB70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-cd] [VpxLRO] -- BEGIN task-internal-135972 -- vpxa -- vpxapi.VpxaService.fetchQuickStats -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:19:04.652Z verbose vpxa[FFEEFB70] [Originator@6876 sub=vpxaVmomi opID=PollQuickStatsLoop-606df6c8-cd] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:19:04.652Z info vpxa[FFEEFB70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-cd] [VpxLRO] -- FINISH task-internal-135972

2016-01-20T20:19:07.841Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:19:27.844Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:19:47.845Z verbose vpxa[FFEEFB70] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

2016-01-20T20:20:04.653Z info vpxa[FFB39B70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-ce] [VpxLRO] -- BEGIN task-internal-135973 -- vpxa -- vpxapi.VpxaService.fetchQuickStats -- 520cbe98-ade2-3ed7-9aa9-de30703fd6ce

2016-01-20T20:20:04.654Z verbose vpxa[FFB39B70] [Originator@6876 sub=vpxaVmomi opID=PollQuickStatsLoop-606df6c8-ce] [VpxaVmomi] SetStatusDone was called with syncGenNo (36206)

2016-01-20T20:20:04.654Z info vpxa[FFB39B70] [Originator@6876 sub=vpxLro opID=PollQuickStatsLoop-606df6c8-ce] [VpxLRO] -- FINISH task-internal-135973

2016-01-20T20:20:07.846Z verbose vpxa[FFAD6A60] [Originator@6876 sub=hostdstats] Set internal stats for VM: 10 (vpxa VM id), 42 (vpxd VM id). Is FT primary? false

[ThompsG]

Hi there,

Sorry if I'm revisiting troubleshooting steps that you have already tried so please bear with me

You mention that you can create new files on the NFS4 datastore - once you create a file can you confirm the owner of this file from ESXi? I'm assuming you create this file from the datastore browser?

Thanks and kind regards,

Glen

[kclarksd83]

Sorry for the late reply.

I created a new folder and a copied a file into it using the vcenter web client. Then I SSH's into the server to look at the permissions on the file, which were:

[root@esc-hv-00:/vmfs/volumes/7bc914c3-38077c80-0000-000000000000] ls -lh

total 16

drwxr-xr-x    2 root     root        4.0K Jan 20 19:10 ISO

drwxr-xr-x    2 root     root        4.0K Jan 20 20:31 Kyle Test

drwxr-xr-x    2 root     root        4.0K Jan 20 19:13 New Folder

drwxr-xr-x    2 root     root        4.0K Jan 26 18:35 Test Folder

-rwxr-xr-x    1 root     root           0 Jan 20 20:31 kyle.txt

[root@esc-hv-00:/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Test Folder] ls -lh

total 4

-rwxr-xr-x    1 root     root        2.4K Jan 26 18:35 IBM-WIN7-TEST2.vmx

[root@esc-hv-00:/vmfs/volumes/7bc914c3-38077c80-0000-000000000000/Test Folder]

Looking at the files on the NFS3 datastore, the permissions all look identical.

[Mosidi_Mosidi]

did you get a solution for this issue?