This is an existing cluster and vMotion between hosts is working fine. We bought a new NFS array and I am in the process of moving our VMs: svMotion worked fine for some VMs but some VMs are failing svMotion with “Failed to initialize the swap file” and I can’t see why.
There isn’t much in vCenter events that is relevant or helpful:
Event Type Description: Failed to migrate the virtual machine for reasons described in the event message
Possible Causes: The virtual machine did not migrate. This condition can occur if vMotion IPs are not configured, the source and destination hosts are not accessible, and so on. Action: Check the reason in the event message to find the cause of the failure. Ensure that the vMotion IPs are configured on source and destination hosts, the hosts are accessible, and so on.
The vmkernel.log directed me to the vmware.log for the VM, but I still can’t figure this out – any ideas why svMotion is failing? I can see the files being created in the target datastore etc.
2020-11-02T15:27:15.339Z| vmx| I125: VigorTransportProcessClientPayload: opID=kfk64jly-8h07s-h5:70281608-15-02-59-7d1f seq=3288: Receiving Migrate.PrepareSource request.
2020-11-02T15:27:15.339Z| vmx| I125: MigrateVMXdrToSpec: type: 2 srcIp=<127.0.0.1> dstIp=<127.0.0.1> mid=8976a899ed87f3c uuid=494f4907-2a69-4f71-b5cf-21b97d144098 priority=no checksumMemory=no maxDowntime=0 encrypted=0 resumeDuringPageIn=no latencyAware=yes diskOpFile= srcLogIp=<<unknown>> dstLogIp=<<unknown>> ftPrimaryIp=<<unknown>> ftSecondaryIp=<<unknown>>
2020-11-02T15:27:15.339Z| vmx| I125: MigrateVMXdrToSpec: scsi:0:0 -> /vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206.vmdk, parent:null, parentShared: 0, rdmDevice: null,transform: 2, numSnapshots: 0, policy: ‘null’
2020-11-02T15:27:15.339Z| vmx| I125: MigrateVMXdrToSpec: scsi:0:1 -> /vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1.vmdk, parent:null, parentShared: 0, rdmDevice: null,transform: 2, numSnapshots: 0, policy: ‘null’
2020-11-02T15:27:15.339Z| vmx| I125: MigrateVMXdrToSpec: type 2 unsharedSwap 1 memMinToTransfer 0 cpuMinToTransfer 0 numDisks 2 numStreamIps 0 numFtStreamIps 0
2020-11-02T15:27:15.339Z| vmx| I125: Received migrate ‘to’ request for mid id 619080613094784828, src ip <127.0.0.1>, dst ip <127.0.0.1>(invalidate source config).
2020-11-02T15:27:15.339Z| vmx| A100: ConfigDB: Setting vmotion.checkpointSVGASize = “18808832”
2020-11-02T15:27:15.339Z| vmx| I125: MigrateSetInfo: state=1 srcIp=<127.0.0.1> dstIp=<127.0.0.1> mid=619080613094784828 uuid=494f4907-2a69-4f71-b5cf-21b97d144098 priority=low
2020-11-02T15:27:15.339Z| vmx| I125: MigrateSetState: Transitioning from state 0 to 1.
2020-11-02T15:27:15.340Z| vmx| I125: MigrateReadHostLog: Hostlog_Dump: Hostlog pnlvspr3206-1451ecb5.hlog
2020-11-02T15:27:15.340Z| vmx| I125: UUID: 494f4907-2a69-4f71-b5cf-21b97d144098
2020-11-02T15:27:15.340Z| vmx| I125: MigID: 619080613094784828
2020-11-02T15:27:15.340Z| vmx| I125: HLState: none
2020-11-02T15:27:15.340Z| vmx| I125: ToFrom: none
2020-11-02T15:27:15.340Z| vmx| I125: MigType: invalid
2020-11-02T15:27:15.340Z| vmx| I125: OpType: nfc
2020-11-02T15:27:15.340Z| vmx| I125: WorldID: 0
2020-11-02T15:27:15.340Z| vmx| I125: Item File S “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.nvram”
2020-11-02T15:27:15.340Z| vmx| I125: Item File S “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/vmware-89.log”
2020-11-02T15:27:15.340Z| vmx| I125: Item File S “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/vmware.log”
2020-11-02T15:27:15.340Z| vmx| I125: Item File S “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/vmware-94.log”
2020-11-02T15:27:15.340Z| vmx| I125: Item File S “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/vmware-92.log”
2020-11-02T15:27:15.340Z| vmx| I125: Item File S “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/vmware-93.log”
2020-11-02T15:27:15.340Z| vmx| I125: Item File S “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/vmware-90.log”
2020-11-02T15:27:15.340Z| vmx| I125: Item File S “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/vmware-91.log”
2020-11-02T15:27:15.340Z| vmx| I125: Item File S “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206-aux.xml”
2020-11-02T15:27:15.340Z| vmx| I125: Item Vm S “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.vmx”
2020-11-02T15:27:15.342Z| vmx| I125: VigorTransport_ServerSendResponse opID=kfk64jly-8h07s-h5:70281608-15-02-59-7d1f seq=3288: Completed Migrate request.
2020-11-02T15:27:16.278Z| vmx| I125: VigorTransportProcessClientPayload: opID=kfk64jly-8h07s-h5:70281608-15-02-8-7d51 seq=3307: Receiving Migrate.MigrateSource request.
2020-11-02T15:27:16.278Z| vmx| I125: Received migrate ‘start’ request for mig id 619080613094784828, dest world id 38942806.
2020-11-02T15:27:16.278Z| vmx| I125: MigrateSetState: Transitioning from state 1 to 2.
2020-11-02T15:27:16.284Z| vmx| I125: WORKER: Creating new group with numThreads=1 (16)
2020-11-02T15:27:16.284Z| Worker#1| I125: MigratePrepareEventNotifyThread: Prepare event start.
2020-11-02T15:27:16.284Z| Worker#1| I125: MigratePrepareEventLog: Prepare event callback complete.
2020-11-02T15:27:16.284Z| vmx| I125: MigratePrepareEventLog: Prepare multiwriter disk handoff complete.
2020-11-02T15:27:16.285Z| vmx| I125: MigratePrepareEventLog: Prepare destination complete.
2020-11-02T15:27:16.285Z| vmx| I125: MigratePrepareEventLog: Prepare vPMem Regions complete.
2020-11-02T15:27:16.285Z| vmx| I125: MigratePrepareEventLog: Prepare event complete.
2020-11-02T15:27:16.285Z| vmx| I125: SVMotion: Enter Phase 1
2020-11-02T15:27:16.366Z| Worker#0| I125: SVMotionDiskGetSrcInfo: disk scsi0:0: type: 11, allocType: 3, capacity: 104857600, grain: 0, numlinks: 1, rdm: null.
2020-11-02T15:27:16.366Z| Worker#0| I125: SVMotionDiskGetDstInfo: disk scsi0:0: type: 11, allocType: 2, capacity: 104857600, grain: 0, numlinks: 1, rdm: null.
2020-11-02T15:27:16.366Z| Worker#0| I125: SVMotionDiskSetup: Adding disk scsi0:0: isRDM: 0, isRemote: 0, skipZeros: 1.
2020-11-02T15:27:16.376Z| Worker#0| I125: SVMotionDiskGetSrcInfo: disk scsi0:1: type: 11, allocType: 3, capacity: 20971520, grain: 0, numlinks: 1, rdm: null.
2020-11-02T15:27:16.376Z| Worker#0| I125: SVMotionDiskGetDstInfo: disk scsi0:1: type: 11, allocType: 2, capacity: 20971520, grain: 0, numlinks: 1, rdm: null.
2020-11-02T15:27:16.376Z| Worker#0| I125: SVMotionDiskSetup: Adding disk scsi0:1: isRDM: 0, isRemote: 0, skipZeros: 1.
2020-11-02T15:27:16.381Z| Worker#0| I125: MigrateSetState: Transitioning from state 2 to 3.
2020-11-02T15:27:16.383Z| Worker#0| I125: Hostlog_AddCleanupItem: Ignoring attempt to re-add /vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.nvram.
2020-11-02T15:27:16.385Z| Worker#0| I125: UTIL: Change file descriptor limit from soft 4326,hard 4326 to soft 8652,hard 8652.
2020-11-02T15:27:16.385Z| Worker#0| I125: SVMotion: Enter Phase 2
2020-11-02T15:27:16.386Z| Worker#0| I125: SVMotionDiskGetCreateExtParams: not using a storage policy to create disk ‘/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206.vmdk’
2020-11-02T15:27:16.386Z| Worker#0| I125: DISKLIB-LIB_CREATE : CREATE: “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206.vmdk” — vmfs capacity=104857600 (50 GB) adapter=lsilogic info=cowGran=0 allocType=1 objType= policy=”
2020-11-02T15:27:16.386Z| Worker#0| I125: DISKLIB-LIB_CREATE : CreateObjExtParams: Object backing type 0 is invalid. Figuring out the most suitable backing type…
2020-11-02T15:27:16.387Z| Worker#0| I125: DISKLIB-LIB_CREATE : CREATE: Creating disk backed by ‘file’
2020-11-02T15:27:16.394Z| Worker#0| I125: DISKLIB-DSCPTR: “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206.vmdk” : creation successful.
2020-11-02T15:27:16.412Z| Worker#0| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206-flat.vmdk” : open successful (17) size = 53687091200, hd = 0. Type 3
2020-11-02T15:27:16.419Z| Worker#0| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206-flat.vmdk” : closed.
2020-11-02T15:27:16.421Z| Worker#0| I125: SVMotionDiskGetCreateExtParams: not using a storage policy to create disk ‘/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1.vmdk’
2020-11-02T15:27:16.421Z| Worker#0| I125: DISKLIB-LIB_CREATE : CREATE: “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1.vmdk” — vmfs capacity=20971520 (10 GB) adapter=lsilogic info=cowGran=0 allocType=1 objType= policy=”
2020-11-02T15:27:16.421Z| Worker#0| I125: DISKLIB-LIB_CREATE : CreateObjExtParams: Object backing type 0 is invalid. Figuring out the most suitable backing type…
2020-11-02T15:27:16.423Z| Worker#0| I125: DISKLIB-LIB_CREATE : CREATE: Creating disk backed by ‘file’
2020-11-02T15:27:16.430Z| Worker#0| I125: DISKLIB-DSCPTR: “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1.vmdk” : creation successful.
2020-11-02T15:27:16.445Z| Worker#0| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1-flat.vmdk” : open successful (17) size = 10737418240, hd = 0. Type 3
2020-11-02T15:27:16.453Z| Worker#0| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1-flat.vmdk” : closed.
2020-11-02T15:27:16.455Z| Worker#0| I125: SVMotion: Enter Phase 3
2020-11-02T15:27:16.468Z| Worker#0| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206-flat.vmdk” : open successful (522) size = 53687091200, hd = 7619118412. Type 3
2020-11-02T15:27:16.468Z| Worker#0| I125: DISKLIB-DSCPTR: Opened [0]: “pnlvspr3206-flat.vmdk” (0x20a)
2020-11-02T15:27:16.468Z| Worker#0| I125: DISKLIB-LINK : Opened ‘/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206.vmdk’ (0x20a): vmfs, 104857600 sectors / 50 GB.
2020-11-02T15:27:16.468Z| Worker#0| I125: DISKLIB-LIB : Opened “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206.vmdk” (flags 0x20a, type vmfs).
2020-11-02T15:27:16.483Z| Worker#0| I125: DDB: “longContentID” = “41dfb39cb5dfa0820315451d9e539987” (was “a2ccdfb7df35d6d503082228fffffffe”)
2020-11-02T15:27:16.503Z| Worker#0| I125: DDB: “uuid” = “60 00 C2 9f 65 0e 0e a1-63 17 51 f9 91 8e 4c 68” (was “60 00 C2 9c a8 23 6d 2b-0d d6 ba 22 92 e6 61 b6”)
2020-11-02T15:27:16.510Z| Worker#0| I125: DDB: “virtualHWVersion” = “9” (was “13”)
2020-11-02T15:27:16.517Z| Worker#0| I125: SVMotionLocalDiskQueryInfo: Got block size -1 for filesystem NFS.
2020-11-02T15:27:16.530Z| Worker#0| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1-flat.vmdk” : open successful (522) size = 10737418240, hd = 10287220046. Type 3
2020-11-02T15:27:16.530Z| Worker#0| I125: DISKLIB-DSCPTR: Opened [0]: “pnlvspr3206_1-flat.vmdk” (0x20a)
2020-11-02T15:27:16.530Z| Worker#0| I125: DISKLIB-LINK : Opened ‘/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1.vmdk’ (0x20a): vmfs, 20971520 sectors / 10 GB.
2020-11-02T15:27:16.530Z| Worker#0| I125: DISKLIB-LIB : Opened “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1.vmdk” (flags 0x20a, type vmfs).
2020-11-02T15:27:16.546Z| Worker#0| I125: DDB: “longContentID” = “db72fbc58906a5f2cfa6cb8490fd7594” (was “a208483940e2dab56ad18c08fffffffe”)
2020-11-02T15:27:16.566Z| Worker#0| I125: DDB: “uuid” = “60 00 C2 9d c3 67 41 f9-9b a2 e6 4f 39 6a bf 55” (was “60 00 C2 9e ce 8b 5d 0e-54 1d b2 70 34 e8 e0 22”)
2020-11-02T15:27:16.572Z| Worker#0| I125: DDB: “virtualHWVersion” = “9” (was “13”)
2020-11-02T15:27:16.579Z| Worker#0| I125: SVMotionLocalDiskQueryInfo: Got block size -1 for filesystem NFS.
2020-11-02T15:27:16.579Z| Worker#0| I125: SVMotion: Enter Phase 4
2020-11-02T15:27:16.596Z| Worker#0| I125: SVMotion: Enter Phase 5
2020-11-02T15:27:16.596Z| Worker#0| I125: SVMotion: Enter Phase 6
2020-11-02T15:27:16.596Z| vcpu-0| I125: Destroying virtual dev for scsi0:0 vscsi=97349
2020-11-02T15:27:16.596Z| vcpu-0| I125: VMMon_VSCSIStopVports: No such target on adapter
2020-11-02T15:27:16.596Z| vcpu-0| I125: Destroying virtual dev for scsi0:1 vscsi=97350
2020-11-02T15:27:16.596Z| vcpu-0| I125: VMMon_VSCSIStopVports: No such target on adapter
2020-11-02T15:27:16.597Z| vcpu-0| W115: VMCI: It is FSR migrate and setting migrate cid to -1428462878
2020-11-02T15:27:16.600Z| Worker#1| I125: DISKLIB-LIB_MISC : Opening mirror node /vmfs/devices/svm/272cb89e4-1c622854c-svmmirror
2020-11-02T15:27:16.600Z| Worker#1| I125: DISKLIB-LIB_MISC : Opening mirror node /vmfs/devices/svm/2aac689bd-2652a854e-svmmirror
2020-11-02T15:27:16.600Z| Worker#1| I125: SVMotion: Enter Phase 7
2020-11-02T15:27:16.600Z| Worker#1| I125: Checkpoint_Unstun: vm stopped for 3819 us
2020-11-02T15:27:16.600Z| vcpu-0| I125: SCSI: switching scsi0 to push completion mode
2020-11-02T15:27:16.600Z| vcpu-0| I125: Creating virtual dev for ‘scsi0:0’.
2020-11-02T15:27:16.600Z| vcpu-0| I125: DumpDiskInfo: scsi0:0 createType=11, capacity = 104857600, numLinks = 1, allocationType = 3
2020-11-02T15:27:16.600Z| vcpu-0| I125: SCSIDiskESXPopulateVDevDesc: Using FS backend
2020-11-02T15:27:16.600Z| vcpu-0| I125: DISKUTIL: scsi0:0 : geometry=6527/255/63
2020-11-02T15:27:16.600Z| vcpu-0| I125: SCSIFilterESXAttachCBRCInt: CBRC not enabled or opened without filters,skipping CBRC filter attach.
2020-11-02T15:27:16.600Z| vcpu-0| I125: SCSIFilterSBDAttachCBRC: device scsi0:0 is not SBD. Skipping CBRC attach SBD way.
2020-11-02T15:27:16.600Z| vcpu-0| I125: Creating virtual dev for ‘scsi0:1’.
2020-11-02T15:27:16.600Z| vcpu-0| I125: DumpDiskInfo: scsi0:1 createType=11, capacity = 20971520, numLinks = 1, allocationType = 3
2020-11-02T15:27:16.600Z| vcpu-0| I125: SCSIDiskESXPopulateVDevDesc: Using FS backend
2020-11-02T15:27:16.600Z| vcpu-0| I125: DISKUTIL: scsi0:1 : geometry=1305/255/63
2020-11-02T15:27:16.600Z| vcpu-0| I125: SCSIFilterESXAttachCBRCInt: CBRC not enabled or opened without filters,skipping CBRC filter attach.
2020-11-02T15:27:16.600Z| vcpu-0| I125: SCSIFilterSBDAttachCBRC: device scsi0:1 is not SBD. Skipping CBRC attach SBD way.
2020-11-02T15:27:16.601Z| vcpu-0| I125: VMXNET3 user: Ethernet0 Driver Info: version = 1345333 gosBits = 2 gosType = 2, gosVer = 25088, gosMisc = 212
2020-11-02T15:27:16.601Z| vcpu-0| I125: VMXNET3 user: Ethernet1 Driver Info: version = 1345333 gosBits = 2 gosType = 2, gosVer = 25088, gosMisc = 212
2020-11-02T15:27:16.601Z| Worker#0| I125: SVMotion: Enter Phase 8
2020-11-02T15:27:16.602Z| Worker#0| I125: Disk/File copy started for /vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.vmdk.
2020-11-02T15:30:51.189Z| vmx| I125: SVMotion: scsi0:0: Disk copy completed for total 51200 MB at 244324 kB/s.
2020-11-02T15:30:51.189Z| Worker#0| I125: Disk/File copy started for /vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1.vmdk.
2020-11-02T15:31:31.007Z| vmx| I125: SVMotion: scsi0:1: Disk copy completed for total 10240 MB at 263341 kB/s.
2020-11-02T15:31:31.008Z| Worker#0| I125: Disk/File copy started for /vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206-ctk.vmdk.
2020-11-02T15:31:31.040Z| vmx| I125: SVMotion: File copy completed for /vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206-ctk.vmdk
2020-11-02T15:31:31.041Z| Worker#0| I125: Disk/File copy started for /vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1-ctk.vmdk.
2020-11-02T15:31:31.053Z| vmx| I125: SVMotion: File copy completed for /vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1-ctk.vmdk
2020-11-02T15:31:31.053Z| Worker#0| I125: Disk/File copy started for /vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.nvram.
2020-11-02T15:31:31.065Z| vmx| I125: SVMotion: File copy completed for /vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.nvram
2020-11-02T15:31:31.065Z| Worker#0| I125: SVMotionMirroredMode: Disk copy phase completed.
2020-11-02T15:31:32.699Z| vmx| I125: MigrateSetState: Transitioning from state 3 to 4.
2020-11-02T15:31:32.699Z| vmx| I125: Migrate: Waiting for Storage vMotion.
2020-11-02T15:31:32.699Z| vmx| I125: Migrate: Preparing to suspend.
2020-11-02T15:31:32.699Z| vmx| I125: Migrate: VM starting stun, waiting 100 seconds for go/no-go message.
2020-11-02T15:31:32.699Z| vcpu-0| I125: Destroying virtual dev for scsi0:0 vscsi=97351
2020-11-02T15:31:32.699Z| vcpu-0| I125: VMMon_VSCSIStopVports: No such target on adapter
2020-11-02T15:31:32.700Z| vcpu-0| I125: Destroying virtual dev for scsi0:1 vscsi=97352
2020-11-02T15:31:32.700Z| vcpu-0| I125: VMMon_VSCSIStopVports: No such target on adapter
2020-11-02T15:31:32.700Z| vcpu-0| W115: VMCI: It is FSR migrate and setting migrate cid to -1428462878
2020-11-02T15:31:32.700Z| Worker#0| I125: SVMotionThreadCompleteMigration: Pausing SvMotion thread pending checkpoint save success…
2020-11-02T15:31:32.700Z| vcpu-0| I125: Migrate_Open: Migrating to <127.0.0.1> with migration id 619080613094784828
2020-11-02T15:31:32.700Z| vcpu-0| I125: Progress -1% (msg.checkpoint.saveStatus)
2020-11-02T15:31:32.701Z| vcpu-0| I125: Checkpointed in VMware ESX, 6.5.0, build-10175896, Linux Host
2020-11-02T15:31:32.702Z| vcpu-0| I125: Progress 1% (none)
2020-11-02T15:31:32.702Z| vcpu-0| I125: Progress 2% (none)
2020-11-02T15:31:32.702Z| vcpu-0| I125: Progress 4% (none)
2020-11-02T15:31:32.703Z| vcpu-0| I125: Progress 5% (none)
2020-11-02T15:31:32.703Z| vcpu-0| I125: Progress 6% (none)
2020-11-02T15:31:32.703Z| vcpu-0| I125: Progress 8% (none)
2020-11-02T15:31:32.703Z| vcpu-0| I125: Progress 9% (none)
2020-11-02T15:31:32.703Z| vcpu-0| I125: Progress 11% (none)
2020-11-02T15:31:32.703Z| vcpu-0| I125: Progress 12% (none)
2020-11-02T15:31:32.703Z| vcpu-0| I125: Progress 13% (none)
2020-11-02T15:31:32.704Z| vcpu-0| I125: Progress 15% (none)
2020-11-02T15:31:32.704Z| vcpu-0| I125: Progress 16% (none)
2020-11-02T15:31:32.704Z| vcpu-0| I125: Progress 18% (none)
2020-11-02T15:31:32.704Z| vcpu-0| I125: Progress 19% (none)
2020-11-02T15:31:32.704Z| vcpu-0| I125: Progress 20% (none)
2020-11-02T15:31:32.704Z| vcpu-0| I125: Progress 22% (none)
2020-11-02T15:31:32.704Z| vcpu-0| I125: Progress 23% (none)
2020-11-02T15:31:32.704Z| vcpu-0| I125: Progress 25% (none)
2020-11-02T15:31:32.704Z| vcpu-0| I125: Progress 26% (none)
2020-11-02T15:31:32.705Z| vcpu-0| I125: Progress 27% (none)
2020-11-02T15:31:32.705Z| vcpu-0| I125: Progress 29% (none)
2020-11-02T15:31:32.705Z| vcpu-0| I125: Progress 30% (none)
2020-11-02T15:31:32.705Z| vcpu-0| I125: Progress 32% (none)
2020-11-02T15:31:32.705Z| vcpu-0| I125: Progress 33% (none)
2020-11-02T15:31:32.705Z| vcpu-0| I125: Progress 34% (none)
2020-11-02T15:31:32.705Z| vcpu-0| I125: Progress 36% (none)
2020-11-02T15:31:32.705Z| vcpu-0| I125: Progress 37% (none)
2020-11-02T15:31:32.706Z| vcpu-0| I125: Progress 39% (none)
2020-11-02T15:31:32.706Z| vcpu-0| I125: Progress 40% (none)
2020-11-02T15:31:32.706Z| vcpu-0| I125: Progress 41% (none)
2020-11-02T15:31:32.706Z| vcpu-0| I125: Progress 43% (none)
2020-11-02T15:31:32.706Z| vcpu-0| I125: Progress 44% (none)
2020-11-02T15:31:32.706Z| vcpu-0| I125: Progress 45% (none)
2020-11-02T15:31:32.706Z| vcpu-0| I125: Progress 47% (none)
2020-11-02T15:31:32.706Z| vcpu-0| I125: Progress 48% (none)
2020-11-02T15:31:32.707Z| vcpu-0| I125: Progress 50% (none)
2020-11-02T15:31:32.707Z| vcpu-0| I125: Progress 51% (none)
2020-11-02T15:31:32.707Z| vcpu-0| I125: Progress 52% (none)
2020-11-02T15:31:32.707Z| vcpu-0| I125: Progress 54% (none)
2020-11-02T15:31:32.707Z| vcpu-0| I125: Progress 55% (none)
2020-11-02T15:31:32.707Z| vcpu-0| I125: Progress 57% (none)
2020-11-02T15:31:32.707Z| vcpu-0| I125: Progress 58% (none)
2020-11-02T15:31:32.707Z| vcpu-0| I125: Progress 59% (none)
2020-11-02T15:31:32.708Z| vcpu-0| I125: Progress 61% (none)
2020-11-02T15:31:32.708Z| vcpu-0| I125: Progress 62% (none)
2020-11-02T15:31:32.708Z| vcpu-0| I125: Progress 64% (none)
2020-11-02T15:31:32.708Z| vcpu-0| I125: Progress 65% (none)
2020-11-02T15:31:32.708Z| vcpu-0| I125: Progress 66% (none)
2020-11-02T15:31:32.708Z| vcpu-0| I125: Progress 68% (none)
2020-11-02T15:31:32.708Z| vcpu-0| I125: Progress 69% (none)
2020-11-02T15:31:32.708Z| vcpu-0| I125: Progress 71% (none)
2020-11-02T15:31:32.708Z| vcpu-0| I125: Progress 72% (none)
2020-11-02T15:31:32.709Z| vcpu-0| I125: Progress 73% (none)
2020-11-02T15:31:32.709Z| vcpu-0| I125: Progress 75% (none)
2020-11-02T15:31:32.709Z| vcpu-0| I125: Progress 76% (none)
2020-11-02T15:31:32.709Z| vcpu-0| I125: Progress 78% (none)
2020-11-02T15:31:32.709Z| vcpu-0| I125: Progress 79% (none)
2020-11-02T15:31:32.709Z| vcpu-0| I125: Progress 80% (none)
2020-11-02T15:31:32.709Z| vcpu-0| I125: Progress 82% (none)
2020-11-02T15:31:32.709Z| vcpu-0| I125: Progress 83% (none)
2020-11-02T15:31:32.709Z| vcpu-0| I125: Progress 85% (none)
2020-11-02T15:31:32.710Z| vcpu-0| I125: Progress 86% (none)
2020-11-02T15:31:32.710Z| vcpu-0| I125: Progress 87% (none)
2020-11-02T15:31:32.710Z| vcpu-0| I125: Progress 89% (none)
2020-11-02T15:31:32.712Z| vcpu-0| I125: Progress 90% (none)
2020-11-02T15:31:32.712Z| vcpu-0| I125: Progress 91% (none)
2020-11-02T15:31:32.712Z| vcpu-0| I125: Progress 93% (none)
2020-11-02T15:31:32.712Z| vcpu-0| I125: Progress 94% (none)
2020-11-02T15:31:32.713Z| vcpu-0| I125: Progress 96% (none)
2020-11-02T15:31:32.713Z| vcpu-0| I125: Progress 97% (none)
2020-11-02T15:31:32.713Z| vcpu-0| I125: Progress 98% (none)
2020-11-02T15:31:32.713Z| vcpu-0| I125: Progress 99% (none)
2020-11-02T15:31:32.714Z| vcpu-0| I125: GuestRpc: Reinitializing Channel 0(toolbox)
2020-11-02T15:31:32.714Z| vcpu-0| I125: GuestMsg: Channel 0, Cannot unpost because the previous post is already completed
2020-11-02T15:31:32.714Z| vcpu-0| I125: Progress 101% (none)
2020-11-02T15:31:32.714Z| Worker#0| I125: SVMotionThreadCompleteMigration: Save callback received. Resuming SvMotion success activities.
2020-11-02T15:31:32.714Z| Worker#0| I125: SVMotion: Enter Phase 9
2020-11-02T15:31:32.742Z| Worker#0| I125: Closing all the disks of the VM.
2020-11-02T15:31:32.742Z| Worker#0| I125: Closing disk ‘scsi0:1’
2020-11-02T15:31:32.742Z| Worker#0| I125: DISKLIB-CBT : Shutting down change tracking for untracked fid 11455072701.
2020-11-02T15:31:32.742Z| Worker#0| I125: DISKLIB-CBT : Successfully disconnected CBT node.
2020-11-02T15:31:33.303Z| Worker#0| I125: DISKLIB-VMFS : “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1-flat.vmdk” : closed.
2020-11-02T15:31:33.303Z| Worker#0| I125: Closing disk ‘scsi0:0’
2020-11-02T15:31:33.305Z| Worker#0| I125: DISKLIB-CBT : Shutting down change tracking for untracked fid 10515876324.
2020-11-02T15:31:33.305Z| Worker#0| I125: DISKLIB-CBT : Successfully disconnected CBT node.
2020-11-02T15:31:33.368Z| Worker#0| I125: DISKLIB-VMFS : “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206-flat.vmdk” : closed.
2020-11-02T15:31:33.370Z| Worker#0| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206-flat.vmdk” : closed.
2020-11-02T15:31:33.371Z| Worker#0| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1-flat.vmdk” : closed.
2020-11-02T15:31:33.371Z| Worker#0| I125: SVMotion: Enter Phase 10
2020-11-02T15:31:33.371Z| Worker#0| I125: SVMotionThreadCompleteMigration: Preparing to close disks…
2020-11-02T15:31:33.379Z| Worker#0| I125: SVMotion: Enter Phase 11
2020-11-02T15:31:33.379Z| vmx| I125: Migrate: VM successfully stunned.
2020-11-02T15:31:33.379Z| vmx| I125: MigrateSetState: Transitioning from state 4 to 5.
2020-11-02T15:31:33.379Z| vmx| I125: Closing all the disks of the VM.
2020-11-02T15:31:33.380Z| Worker#1| I125: Migrate: Remote Log: Destination waited for 257.11 seconds.
2020-11-02T15:31:33.380Z| Worker#0| I125: Migrate: Remote Log: Beginning checkpoint restore.
2020-11-02T15:31:33.380Z| Worker#0| I125: Migrate: Remote Log: Switching to checkpoint state.
2020-11-02T15:31:33.403Z| vmx| I125: MigrateSetStateFinished: type=1 new state=6
2020-11-02T15:31:33.403Z| vmx| I125: MigrateSetState: Transitioning from state 5 to 6.
2020-11-02T15:31:33.403Z| vmx| A100: ConfigDB: Setting config.readOnly = “FALSE”
2020-11-02T15:31:33.403Z| vmx| I125: Migrate_SetFailureMsgList: switching to new log file.
2020-11-02T15:31:33.404Z| vmx| I125: Migrate_SetFailureMsgList: Now in new log file.
2020-11-02T15:31:33.404Z| vmx| I125: Migrate: Caching migration error message list:
2020-11-02T15:31:33.404Z| vmx| I125: [msg.migrate.fail.dst] The source detected that the destination failed to resume.
2020-11-02T15:31:33.404Z| vmx| I125: SVMotion: Enter Phase 12
2020-11-02T15:31:33.404Z| vmx| I125: SVMotion_Cleanup: Scheduling cleanup thread.
2020-11-02T15:31:33.404Z| vmx| I125: Migrate: Attempting to continue running on the source.
2020-11-02T15:31:33.404Z| Worker#1| I125: SVMotionCleanupThread: Waiting for SVMotion Bitmap thread to complete.
2020-11-02T15:31:33.404Z| vmx| I125: Checkpoint_Unstun: vm stopped for 704575 us
2020-11-02T15:31:33.404Z| Worker#1| I125: SVMotionCleanupThread: Waiting for SVMotion thread to complete.
2020-11-02T15:31:33.404Z| vcpu-0| I125: SCSI: switching scsi0 to push completion mode
2020-11-02T15:31:33.410Z| vcpu-0| A100: ConfigDB: Setting scsi0:0.redo = “”
2020-11-02T15:31:33.410Z| vcpu-0| I125: DISK: OPEN scsi0:0 ‘/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.vmdk’ persistent R[]
2020-11-02T15:31:33.468Z| vcpu-0| I125: DISKLIB-VMFS : “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206-flat.vmdk” : open successful (10) size = 53687091200, hd = 9232483656. Type 3
2020-11-02T15:31:33.468Z| vcpu-0| I125: DISKLIB-DSCPTR: Opened [0]: “pnlvspr3206-flat.vmdk” (0xa)
2020-11-02T15:31:33.468Z| vcpu-0| I125: DISKLIB-LINK : Opened ‘/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.vmdk’ (0xa): vmfs, 104857600 sectors / 50 GB.
2020-11-02T15:31:33.468Z| vcpu-0| I125: DISKLIB-LIB_BLOCKTRACK : Resuming change tracking.
2020-11-02T15:31:33.470Z| vcpu-0| I125: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 9232483656.
2020-11-02T15:31:33.470Z| vcpu-0| I125: DISKLIB-CBT : Successfuly created cbt node 2264c8548-cbt.
2020-11-02T15:31:33.470Z| vcpu-0| I125: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/2264c8548-cbt
2020-11-02T15:31:33.470Z| vcpu-0| I125: DISKLIB-LIB : Opened “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.vmdk” (flags 0xa, type vmfs).
2020-11-02T15:31:33.470Z| vcpu-0| I125: DISK: Disk ‘/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.vmdk’ has UUID ’60 00 c2 9f 65 0e 0e a1-63 17 51 f9 91 8e 4c 68′
2020-11-02T15:31:33.470Z| vcpu-0| I125: DISK: OPEN ‘/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.vmdk’ Geo (6527/255/63) BIOS Geo (0/0/0)
2020-11-02T15:31:33.471Z| vcpu-0| I125: Creating virtual dev for ‘scsi0:0’.
2020-11-02T15:31:33.471Z| vcpu-0| I125: DumpDiskInfo: scsi0:0 createType=11, capacity = 104857600, numLinks = 1, allocationType = 3
2020-11-02T15:31:33.471Z| vcpu-0| I125: SCSIDiskESXPopulateVDevDesc: Using FS backend
2020-11-02T15:31:33.471Z| vcpu-0| I125: DISKUTIL: scsi0:0 : geometry=6527/255/63
2020-11-02T15:31:33.471Z| vcpu-0| I125: SCSIFilterESXAttachCBRCInt: CBRC not enabled or opened without filters,skipping CBRC filter attach.
2020-11-02T15:31:33.471Z| vcpu-0| I125: SCSIFilterSBDAttachCBRC: device scsi0:0 is not SBD. Skipping CBRC attach SBD way.
2020-11-02T15:31:33.478Z| vcpu-0| A100: ConfigDB: Setting scsi0:1.redo = “”
2020-11-02T15:31:33.478Z| vcpu-0| I125: DISK: OPEN scsi0:1 ‘/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1.vmdk’ persistent R[]
2020-11-02T15:31:33.521Z| vcpu-0| I125: DISKLIB-VMFS : “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1-flat.vmdk” : open successful (10) size = 10737418240, hd = 10528261451. Type 3
2020-11-02T15:31:33.521Z| vcpu-0| I125: DISKLIB-DSCPTR: Opened [0]: “pnlvspr3206_1-flat.vmdk” (0xa)
2020-11-02T15:31:33.521Z| vcpu-0| I125: DISKLIB-LINK : Opened ‘/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1.vmdk’ (0xa): vmfs, 20971520 sectors / 10 GB.
2020-11-02T15:31:33.521Z| vcpu-0| I125: DISKLIB-LIB_BLOCKTRACK : Resuming change tracking.
2020-11-02T15:31:33.525Z| vcpu-0| I125: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 10528261451.
2020-11-02T15:31:33.525Z| vcpu-0| I125: DISKLIB-CBT : Successfuly created cbt node 27388854b-cbt.
2020-11-02T15:31:33.525Z| vcpu-0| I125: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/27388854b-cbt
2020-11-02T15:31:33.525Z| vcpu-0| I125: DISKLIB-LIB : Opened “/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1.vmdk” (flags 0xa, type vmfs).
2020-11-02T15:31:33.525Z| vcpu-0| I125: DISK: Disk ‘/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1.vmdk’ has UUID ’60 00 c2 9d c3 67 41 f9-9b a2 e6 4f 39 6a bf 55′
2020-11-02T15:31:33.525Z| vcpu-0| I125: DISK: OPEN ‘/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1.vmdk’ Geo (1305/255/63) BIOS Geo (0/0/0)
2020-11-02T15:31:33.525Z| vcpu-0| I125: Creating virtual dev for ‘scsi0:1’.
2020-11-02T15:31:33.525Z| vcpu-0| I125: DumpDiskInfo: scsi0:1 createType=11, capacity = 20971520, numLinks = 1, allocationType = 3
2020-11-02T15:31:33.525Z| vcpu-0| I125: SCSIDiskESXPopulateVDevDesc: Using FS backend
2020-11-02T15:31:33.525Z| vcpu-0| I125: DISKUTIL: scsi0:1 : geometry=1305/255/63
2020-11-02T15:31:33.525Z| vcpu-0| I125: SCSIFilterESXAttachCBRCInt: CBRC not enabled or opened without filters,skipping CBRC filter attach.
2020-11-02T15:31:33.525Z| vcpu-0| I125: SCSIFilterSBDAttachCBRC: device scsi0:1 is not SBD. Skipping CBRC attach SBD way.
2020-11-02T15:31:33.526Z| vcpu-0| I125: VMXNET3 user: Ethernet0 Driver Info: version = 1345333 gosBits = 2 gosType = 2, gosVer = 25088, gosMisc = 212
2020-11-02T15:31:33.526Z| vcpu-0| I125: VMXNET3 user: Ethernet1 Driver Info: version = 1345333 gosBits = 2 gosType = 2, gosVer = 25088, gosMisc = 212
2020-11-02T15:31:33.527Z| vcpu-0| I125: Migrate: cleaning up migration state.
2020-11-02T15:31:33.534Z| vcpu-0| I125: SVMotion_Cleanup: Cleanup thread already scheduled. Ignoring second cleanup request
2020-11-02T15:31:33.534Z| vmx| I125: SVMotion: Worker thread performing SVMotionCopyThreadDone exited.
2020-11-02T15:31:33.534Z| Worker#1| I125: SVMotionCleanupThread: Waiting for final stun/unstun to finish
2020-11-02T15:31:33.534Z| Worker#1| I125: SVMotionCleanupThread: Cleaning up files.
2020-11-02T15:31:33.534Z| Worker#1| I125: SVMotionCleanupThread: Cleaning up disks.
2020-11-02T15:31:33.535Z| vcpu-0| W115: GuestRpc: application toolbox, changing channel 65535 -> 0
2020-11-02T15:31:33.535Z| vcpu-0| I125: GuestRpc: Channel 0, guest application toolbox.
2020-11-02T15:31:33.541Z| Worker#1| I125: MigrateDeleteHostLogItem: Attempting to delete /vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1.vmdk (0).
2020-11-02T15:31:33.545Z| vcpu-1| I125: TOOLS autoupgrade protocol version 2
2020-11-02T15:31:33.545Z| vcpu-1| I125: Vix: [39035041 mainDispatch.c:4151]: VMAutomationReportPowerStateChange: Reporting power state change (opcode=2, err=0).
2020-11-02T15:31:33.545Z| vcpu-1| I125: TOOLS Received tools.set.version rpc call, version = 9359, setting type to 1 from guest OS
2020-11-02T15:31:33.545Z| vcpu-1| I125: Tools_SetVersionAndType did nothing; new tools version (9359) and type (1) match old Tools version and type
2020-11-02T15:31:33.547Z| Worker#1| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1-flat.vmdk” : open successful (1115153) size = 0, hd = 0. Type 3
2020-11-02T15:31:33.547Z| Worker#1| I125: DISKLIB-LIB_BLOCKTRACK : Resuming change tracking.
2020-11-02T15:31:33.563Z| Worker#1| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1-flat.vmdk” : closed.
2020-11-02T15:31:33.572Z| Worker#1| I125: MigrateDeleteHostLogItem: Attempting to delete /vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206.vmdk (0).
2020-11-02T15:31:33.581Z| Worker#1| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206-flat.vmdk” : open successful (1115153) size = 0, hd = 0. Type 3
2020-11-02T15:31:33.581Z| Worker#1| I125: DISKLIB-LIB_BLOCKTRACK : Resuming change tracking.
2020-11-02T15:31:33.608Z| Worker#1| I125: DISKLIB-VMFS : “/vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206-flat.vmdk” : closed.
2020-11-02T15:31:33.619Z| Worker#1| I125: MigrateDeleteHostLogItem: Attempting to delete /vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206-ctk.vmdk (1).
2020-11-02T15:31:33.622Z| Worker#1| I125: MigrateDeleteHostLogItem: Attempting to delete /vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206_1-ctk.vmdk (1).
2020-11-02T15:31:33.626Z| Worker#1| I125: MigrateDeleteHostLogItem: Attempting to delete /vmfs/volumes/740fa108-e4b75a93/pnlvspr3206/pnlvspr3206.nvram (1).
2020-11-02T15:31:33.632Z| Worker#1| I125: VigorTransport_ServerSendResponse opID=kfk64jly-8h07s-h5:70281608-15-02-8-7d51 seq=3307: Completed Migrate request.
2020-11-02T15:31:33.632Z| Worker#1| I125: Migrate: Final status reported through Vigor.
2020-11-02T15:31:33.632Z| Worker#1| I125: MigrateSetState: Transitioning from state 6 to 0.
2020-11-02T15:31:33.632Z| Worker#1| I125: SVMotion: Enter Phase 0
2020-11-02T15:31:33.632Z| Worker#1| I125: SVMotionCleanupThread: Cleanup complete.
2020-11-02T15:31:34.135Z| vcpu-0| I125: HBACommon: First write on scsi0:1.fileName=’/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206_1.vmdk’
2020-11-02T15:31:34.135Z| vcpu-0| I125: DDB: “longContentID” = “79b2a1c29d0e7c33733f2261febeb1e4” (was “db72fbc58906a5f2cfa6cb8490fd7594”)
2020-11-02T15:31:34.149Z| vcpu-0| I125: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x90fd7594, new=0xfebeb1e4 (79b2a1c29d0e7c33733f2261febeb1e4)
2020-11-02T15:31:34.863Z| vcpu-0| I125: HBACommon: First write on scsi0:0.fileName=’/vmfs/volumes/a0473f7a-e97ae3eb/pnlvspr3206/pnlvspr3206.vmdk’
2020-11-02T15:31:34.863Z| vcpu-0| I125: DDB: “longContentID” = “acb9bf96cbe49fc31eb185ba71f941db” (was “41dfb39cb5dfa0820315451d9e539987”)
2020-11-02T15:31:34.879Z| vcpu-0| I125: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x9e539987, new=0x71f941db (acb9bf96cbe49fc31eb185ba71f941db)