We've recently started doing policy based storage and now are noticing sometimes with a "power on" task or when VMs are migrated either user or DRS initiated the task gets stuck for 3-5 minutes with "invoking prechecks" in the task details.
I tailed the vpxd log today during a migration and noticed that it seems the policy based storage is causing some headaches.
Has anyone run into this before and is there an easy solution? We're using this for SRM and now have SRM working the way we want but these delayed migrations and power on's don't work for us.
2017-11-09T13:47:13.175Z info vpxd[7FAAC72E9700] [Originator@6876 sub=vpxLro opID=979D0DE7-0000094A-fe] [VpxLRO] -- BEGIN task-2823881 -- vm-20066 -- vim.VirtualMachine.migrate -- 520d1ccf-d75a-0ce4-5f30-409cd1145712(524c731f-297d-6b90-48d0-8a9ef3473746)
2017-11-09T13:47:13.247Z warning vpxd[7FAACF0E3700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-8c] NotifyChange: null collector in filter: (0x7fab3f0574d0, null)
2017-11-09T13:47:13.247Z warning vpxd[7FAACF0E3700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-8c] NotifyChange: null collector in filter: (0x7fab19d9d7c0, null)
2017-11-09T13:47:13.247Z warning vpxd[7FAACF0E3700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-8c] NotifyChange: null collector in filter: (0x7faaf9c0e4d0, null)
2017-11-09T13:47:13.247Z warning vpxd[7FAACF0E3700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-8c] NotifyChange: null collector in filter: (0x7fab4ad679e0, null)
2017-11-09T13:47:13.247Z warning vpxd[7FAACF0E3700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-8c] NotifyChange: null collector in filter: (0x7fab029e5740, null)
2017-11-09T13:47:13.247Z warning vpxd[7FAACF0E3700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-8c] NotifyChange: null collector in filter: (0x7fab0a2a8930, null)
2017-11-09T13:47:13.247Z warning vpxd[7FAACF0E3700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-8c] NotifyChange: null collector in filter: (0x7fab0d625d70, null)
2017-11-09T13:47:13.247Z warning vpxd[7FAACF0E3700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-8c] NotifyChange: null collector in filter: (0x7faaf29d8210, null)
2017-11-09T13:47:13.247Z warning vpxd[7FAACF0E3700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-8c] NotifyChange: null collector in filter: (0x7fab7216b4a0, null)
2017-11-09T13:47:13.280Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering PreMigrateCheckCallback
2017-11-09T13:47:13.280Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering QueryAssociatedProfiles
2017-11-09T13:47:13.280Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering QueryAssociatedProfilesCache
2017-11-09T13:47:13.280Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving QueryAssociatedProfilesCache
2017-11-09T13:47:13.280Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving QueryAssociatedProfiles
2017-11-09T13:47:13.280Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: CheckForDatastoreDefaultFlagAndUpdate: Profile filled from source profile: 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7
2017-11-09T13:47:13.280Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering GetPolicyBlob
2017-11-09T13:47:13.280Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: RetrieveContentAsString: Retrieve profile content for profile 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7, datastore-15463
2017-11-09T13:50:08.016Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] RetrieveContentAsString [RetrieveContentAsString] took 174735 ms
2017-11-09T13:50:08.016Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving GetPolicyBlob
2017-11-09T13:50:08.016Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] GetPolicyBlob [GetPolicyBlob] took 174735 ms
2017-11-09T13:50:08.016Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] ProcessProfiles [ProcessProfiles] took 174735 ms
2017-11-09T13:50:08.016Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] GetAndSetVmHomeProfileFromRelocate [GetAndSetVmHomeProfileFromRelocate] took 174735 ms
2017-11-09T13:50:08.016Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] FillRelocateSpecWithSourceVmHome [FillRelocateSpecWithSourceVmHome] took 174735 ms
2017-11-09T13:50:08.016Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: CheckForDatastoreDefaultFlagAndUpdate: Profile filled from source profile: 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7
2017-11-09T13:50:08.016Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering GetPolicyBlob
2017-11-09T13:50:08.016Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: RetrieveContentAsString: Retrieve profile content for profile 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7, datastore-15463
2017-11-09T13:50:54.596Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] RetrieveContentAsString [RetrieveContentAsString] took 46580 ms
2017-11-09T13:50:54.596Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving GetPolicyBlob
2017-11-09T13:50:54.596Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] GetPolicyBlob [GetPolicyBlob] took 46580 ms
2017-11-09T13:50:54.596Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] ProcessProfiles [ProcessProfiles] took 46580 ms
2017-11-09T13:50:54.596Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: CheckForDatastoreDefaultFlagAndUpdate: Profile filled from source profile: 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7
2017-11-09T13:50:54.596Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering GetPolicyBlob
2017-11-09T13:50:54.596Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: RetrieveContentAsString: Retrieve profile content for profile 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7, datastore-15463
2017-11-09T13:50:56.800Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving GetPolicyBlob
2017-11-09T13:50:56.800Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: CheckForDatastoreDefaultFlagAndUpdate: Profile filled from source profile: 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7
2017-11-09T13:50:56.800Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering GetPolicyBlob
2017-11-09T13:50:56.800Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: RetrieveContentAsString: Retrieve profile content for profile 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7, datastore-15463
2017-11-09T13:50:57.238Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving GetPolicyBlob
2017-11-09T13:50:57.238Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: CheckForDatastoreDefaultFlagAndUpdate: Profile filled from source profile: 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7
2017-11-09T13:50:57.238Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering GetPolicyBlob
2017-11-09T13:50:57.238Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: RetrieveContentAsString: Retrieve profile content for profile 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7, datastore-15463
2017-11-09T13:50:57.304Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving GetPolicyBlob
2017-11-09T13:50:57.304Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: CheckForDatastoreDefaultFlagAndUpdate: Profile filled from source profile: 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7
2017-11-09T13:50:57.304Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering GetPolicyBlob
2017-11-09T13:50:57.304Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: RetrieveContentAsString: Retrieve profile content for profile 4f67c7f0-b2aa-4652-b2e3-5ff9859ed9a7, datastore-15463
2017-11-09T13:50:57.369Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving GetPolicyBlob
2017-11-09T13:50:57.369Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] FillRelocateSpecWithSourceVm [FillRelocateSpecWithSourceVm] took 224089 ms
2017-11-09T13:50:57.369Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving PreMigrateCheckCallback
2017-11-09T13:50:57.369Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PreMigrateCheckCallback [PreMigrateCheckCallback] took 224089 ms
2017-11-09T13:50:57.369Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] InvokeListenerPrecheck [PbmCallBack] took 224089 ms
2017-11-09T13:50:57.370Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.SelectDestination (1%)
2017-11-09T13:50:57.371Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.CheckCompatibility (1%)
2017-11-09T13:50:57.372Z info vpxd[7FAAC72E9700] [Originator@6876 sub=vpxLro opID=979D0DE7-0000094A-fe-20-26] [VpxLRO] -- BEGIN task-internal-63197966 -- -- VmTestDriver --
2017-11-09T13:50:57.374Z info vpxd[7FAAC72E9700] [Originator@6876 sub=vpxLro opID=979D0DE7-0000094A-fe-20-26] [VpxLRO] -- FINISH task-internal-63197966
2017-11-09T13:50:57.374Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.ReserveDirectory (5%)
2017-11-09T13:50:57.396Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.ComputeSpecs (1%)
2017-11-09T13:50:57.396Z error vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [ComputeSpecsImpl] Cannot find virtual nic for vnic type vSphereProvisioning
2017-11-09T13:50:57.403Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.InvokeCallbacks (5%)
2017-11-09T13:50:57.403Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on AutoStartManager
2017-11-09T13:50:57.403Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on ContextValidator
2017-11-09T13:50:57.403Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on DAS
2017-11-09T13:50:57.403Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on DVS
2017-11-09T13:50:57.403Z info vpxd[7FAAC72E9700] [Originator@6876 sub=coreanchor opID=979D0DE7-0000094A-fe-20] [MoDVSwitch::UpdatePortProxyHostInt] updating port [9303] proxy host to [host-10067]
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on EventEmitter
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on InvtId
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on Iofilter
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on MetadataHandler
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on PbmCallBack
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering PreMigrateCallback
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering FillSpec
2017-11-09T13:50:57.413Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: FillConfigSpec: ConfigSpec is NULL
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving FillSpec
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving PreMigrateCallback
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on PermissionsHandler
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on VApp
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on ResManager
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on DRM
2017-11-09T13:50:57.413Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on ResourceReservation
2017-11-09T13:50:57.416Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on OCM
2017-11-09T13:50:57.416Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [CallbackManager] Invoke pre callback on StorageListeners
2017-11-09T13:50:57.437Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.PrepareSource (1%)
2017-11-09T13:50:57.505Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.PrepareDestination (1%)
2017-11-09T13:50:57.548Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.InitiateDestination (1%)
2017-11-09T13:50:57.901Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.InitiateSource (76%)
2017-11-09T13:51:01.928Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.SwitchHostAndPool (1%)
2017-11-09T13:51:01.952Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=VmprovUtil opID=979D0DE7-0000094A-fe-20] [PatchConfig] Not persisting the serial port network backings. If you have VMs with network backings for serial ports, please set config option: vpxd.SerialPort.PersistNetworkBacking.
2017-11-09T13:51:01.959Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab3f0574d0, null)
2017-11-09T13:51:01.959Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab19d9d7c0, null)
2017-11-09T13:51:01.959Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7faaf9c0e4d0, null)
2017-11-09T13:51:01.959Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab4ad679e0, null)
2017-11-09T13:51:01.959Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab029e5740, null)
2017-11-09T13:51:01.959Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab0a2a8930, null)
2017-11-09T13:51:01.959Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab0d625d70, null)
2017-11-09T13:51:01.959Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7faaf29d8210, null)
2017-11-09T13:51:01.959Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab7216b4a0, null)
2017-11-09T13:51:01.991Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering PostMigrateCallback
2017-11-09T13:51:01.991Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ReconfigVmAssociations: Reconfigure profile association for vm vm-20066
2017-11-09T13:51:01.991Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: PbmFunctionTracer: Entering ReconfigVmAssociations
2017-11-09T13:51:02.135Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving ReconfigVmAssociations
2017-11-09T13:51:02.135Z info vpxd[7FAAC72E9700] [Originator@6876 sub=pbm opID=979D0DE7-0000094A-fe-20] PBMCallback: ~PbmFunctionTracer: Leaving PostMigrateCallback
2017-11-09T13:51:02.136Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=VmprovUtil opID=979D0DE7-0000094A-fe-20] [PatchConfig] Not persisting the serial port network backings. If you have VMs with network backings for serial ports, please set config option: vpxd.SerialPort.PersistNetworkBacking.
2017-11-09T13:51:02.142Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab3f0574d0, null)
2017-11-09T13:51:02.142Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab19d9d7c0, null)
2017-11-09T13:51:02.142Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7faaf9c0e4d0, null)
2017-11-09T13:51:02.142Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab4ad679e0, null)
2017-11-09T13:51:02.142Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab029e5740, null)
2017-11-09T13:51:02.142Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab0a2a8930, null)
2017-11-09T13:51:02.142Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab0d625d70, null)
2017-11-09T13:51:02.142Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7faaf29d8210, null)
2017-11-09T13:51:02.142Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20] NotifyChange: null collector in filter: (0x7fab7216b4a0, null)
2017-11-09T13:51:02.142Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.CompleteSource (1%)
2017-11-09T13:51:02.160Z info vpxd[7FAAEEBD7700] [Originator@6876 sub=InvtHostCnx opID=979D0DE7-0000094A-fe-20-23] Not persisting vFlash resource runtime info. If you have hosts configured with vFlash resource, please set vpxd config option: vpxd.PersistVFlashRuntimeInfo to true.
2017-11-09T13:51:02.190Z info vpxd[7FAAC72E9700] [Originator@6876 sub=VmProv opID=979D0DE7-0000094A-fe-20] [WorkflowImpl] Execute local action vpx.vmprov.CompleteDestination (1%)
2017-11-09T13:51:02.225Z info vpxd[7FAAD17B0700] [Originator@6876 sub=InvtHostCnx opID=979D0DE7-0000094A-fe-20-94] Not persisting vFlash resource runtime info. If you have hosts configured with vFlash resource, please set vpxd config option: vpxd.PersistVFlashRuntimeInfo to true.
2017-11-09T13:51:02.233Z warning vpxd[7FAAD17B0700] [Originator@6876 sub=VmprovUtil opID=979D0DE7-0000094A-fe-20-94] [PatchConfig] Not persisting the serial port network backings. If you have VMs with network backings for serial ports, please set config option: vpxd.SerialPort.PersistNetworkBacking.
2017-11-09T13:51:02.266Z warning vpxd[7FAAD17B0700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20-94] NotifyChange: null collector in filter: (0x7fab3f0574d0, null)
2017-11-09T13:51:02.266Z warning vpxd[7FAAD17B0700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20-94] NotifyChange: null collector in filter: (0x7fab19d9d7c0, null)
2017-11-09T13:51:02.266Z warning vpxd[7FAAD17B0700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20-94] NotifyChange: null collector in filter: (0x7faaf9c0e4d0, null)
2017-11-09T13:51:02.266Z warning vpxd[7FAAD17B0700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20-94] NotifyChange: null collector in filter: (0x7fab4ad679e0, null)
2017-11-09T13:51:02.266Z warning vpxd[7FAAD17B0700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20-94] NotifyChange: null collector in filter: (0x7fab029e5740, null)
2017-11-09T13:51:02.266Z warning vpxd[7FAAD17B0700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20-94] NotifyChange: null collector in filter: (0x7fab0a2a8930, null)
2017-11-09T13:51:02.266Z warning vpxd[7FAAD17B0700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20-94] NotifyChange: null collector in filter: (0x7fab0d625d70, null)
2017-11-09T13:51:02.266Z warning vpxd[7FAAD17B0700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20-94] NotifyChange: null collector in filter: (0x7faaf29d8210, null)
2017-11-09T13:51:02.266Z warning vpxd[7FAAD17B0700] [Originator@6876 sub=PropertyCollector opID=979D0DE7-0000094A-fe-20-94] NotifyChange: null collector in filter: (0x7fab7216b4a0, null)
2017-11-09T13:51:02.269Z warning vpxd[7FAAC72E9700] [Originator@6876 sub=VpxProfiler opID=979D0DE7-0000094A-fe-20] VpxLro::LroMain [TotalTime] took 228989 ms
2017-11-09T13:51:02.269Z info vpxd[7FAAC72E9700] [Originator@6876 sub=vpxLro opID=979D0DE7-0000094A-fe-20] [VpxLRO] -- FINISH task-internal-63197537
2017-11-09T13:51:02.271Z warning vpxd[7FAACC893700] [Originator@6876 sub=VpxProfiler opID=979D0DE7-0000094A-fe-20-TaskLoop-103f83ac] TaskLoop [TotalTime] took 4746 ms
2017-11-09T13:51:02.273Z warning vpxd[7FAAFC50A700] [Originator@6876 sub=VpxProfiler opID=979D0DE7-0000094A-fe-20-TaskLoop-dadba5b] TaskLoop [TotalTime] took 4812 ms
2017-11-09T13:51:02.274Z info vpxd[7FAAC72E9700] [Originator@6876 sub=vpxLro opID=979D0DE7-0000094A-fe] [VpxLRO] -- FINISH task-2823881