Vmotion fails at 90%, Incorrect name of swap file in vmware.log

[steppylud]

Hi. I have seen the same issue reported but no resolution seems to work for me.

Setup.

Two Clusters of 2 ESX 3.02 Hosts on each side. 35 VM's on each cluster. Storage are a seperate Netapp NFS volume for each cluster. 7 VM's on Cluster 1 refusing to VMotion. They get to 90% and the good old 'General Error' message pops up. If I look at the vmware.log file for the machine I see the following line. Unable to initialize swap file /vmfs/volumes/28464ebb-2b9cca5f/DESTINYSRV001/DESTINYSRV001-5cfcd301.vswp Note that the .vswp file is the incorrect name. The VM's were all registered in VI.

Things I have tried:

Cold Migration - Works fine

Cold Migration to other host then VMotion - Not Working.

Shutdown, Migrate to other cluster, Power On and VMotion - Works Fine

vmware-cmd -s unregister/register using UUID or friendly name - Not working

I am a bit stuck now, and not sure what else there is to try. I am guessing as the VMotion works fine on the other cluster there is s a problem with how the storage is being accessed? Help!

[steppylud]

Surely I haven't baffled everyone???

[pcomo]

Hi,

Have you in vmware.log of VM directory, line with " snapshot exist"....?

Try to make a snapshot of the VM and delete it, if snapshot file still exist after delete, try to re-crate snapshot and delete all in snapshot manager.

For us this solution corrected the problem.

I hope that we can help you.

[pcomo]

Hi,

Do you have any update on this?

Thanks.

[steppylud]

Hi, thanks for the reply.

No snapshots at all. I tried to create one and delete it, snapshot file removed itself. Tried Vmotion, still not working!

Thanks.

[cloggs1]

Can you post the log file

[steppylud]

Jan 21 17:00:02.406: vmx| Log for VMware ESX Server pid=101423 version=3.0.2 build=build-62488 option=Release

Jan 21 17:00:02.412: vmx| Hostname=esx-srv001.localdomain.com

Jan 21 17:00:02.412: vmx| Command line: "/usr/lib/vmware/bin/vmware-vmx" "-ssched.group=host/user" "-@" "pipe=/tmp/vmhsdaemon-0/vmxe7568344c02271ff;vm=e7568344c02271ff" "/vmfs/volumes/28464ebb-2b9cca5f/serverSRV005/serverSRV005.vmx"

Jan 21 17:00:02.462: vmx| UI Connecting to pipe '/tmp/vmhsdaemon-0/vmxe7568344c02271ff' with user '(null)'

Jan 21 17:00:02.500: vmx| pcpu #0 CPUID numEntries=1 AuthcAMDenti

Jan 21 17:00:02.500: vmx| pcpu #0 CPUID version=0x20f12 id1.edx=0x178bfbff id1.ecx=0x1 id1.ebx=0x20800

Jan 21 17:00:02.500: vmx| pcpu #0 CPUID id80.eax=80000018 id81.edx=0xe3d3fbff id81.ecx=0x2

Jan 21 17:00:02.500: vmx| pcpu #1 CPUID numEntries=1 AuthcAMDenti

Jan 21 17:00:02.500: vmx| pcpu #1 CPUID version=0x20f12 id1.edx=0x178bfbff id1.ecx=0x1 id1.ebx=0x1020800

Jan 21 17:00:02.501: vmx| pcpu #1 CPUID id80.eax=80000018 id81.edx=0xe3d3fbff id81.ecx=0x2

Jan 21 17:00:02.501: vmx| pcpu #2 CPUID numEntries=1 AuthcAMDenti

Jan 21 17:00:02.501: vmx| pcpu #2 CPUID version=0x20f12 id1.edx=0x178bfbff id1.ecx=0x1 id1.ebx=0x2020800

Jan 21 17:00:02.501: vmx| pcpu #2 CPUID id80.eax=80000018 id81.edx=0xe3d3fbff id81.ecx=0x2

Jan 21 17:00:02.501: vmx| pcpu #3 CPUID numEntries=1 AuthcAMDenti

Jan 21 17:00:02.501: vmx| pcpu #3 CPUID version=0x20f12 id1.edx=0x178bfbff id1.ecx=0x1 id1.ebx=0x3020800

Jan 21 17:00:02.501: vmx| pcpu #3 CPUID id80.eax=80000018 id81.edx=0xe3d3fbff id81.ecx=0x2

Jan 21 17:00:02.505: vmx| CPUID id1.edx: 0x178bfbff id1.ecx: 0x1 id81.edx: 0xe3d3fbff id81.ecx: 0x2

Jan 21 17:00:02.505: vmx| CPUID id88.ecx: 0 id88.edx: 0

Jan 21 17:00:02.505: vmx| CPUID Maximum Physical Address Bits supported across all CPUs : 40

Jan 21 17:00:02.519: vmx| Setup symlink /var/run/vmware/%2fvmfs%2fvolumes%2f28464ebb%2d2b9cca5f%2fserverSRV005%2fserverSRV005%2evmx -> /var/run/vmware/root_0/1200934802415097_101423

Jan 21 17:00:02.519: vmx| ACL_InitCapabilities: current IPC thread

Jan 21 17:00:02.521: vmx| ACL_InitCapabilities: done

Jan 21 17:00:02.522: vmx| changing directory to /vmfs/volumes/28464ebb-2b9cca5f/serverSRV005/.

Jan 21 17:00:02.522: vmx| Config file: /vmfs/volumes/28464ebb-2b9cca5f/serverSRV005/serverSRV005.vmx

Jan 21 17:00:02.611: vmx| DISKLIB-VMFS : "/vmfs/volumes/28464ebb-2b9cca5f/serverSRV005/serverSRV005-flat.vmdk" : open successful (23) size = 8602272768, hd = -1. Type 3

Jan 21 17:00:02.613: vmx| DISKLIB-VMFS : "/vmfs/volumes/28464ebb-2b9cca5f/serverSRV005/serverSRV005-flat.vmdk" : closed.

Jan 21 17:00:02.696: vmx| VMXVmdb_LoadRawConfig: Loading raw config

Jan 21 17:00:02.746: vmx| VMXVmdbCbVmVmxMigrate: Got SET callback for /vm/#e7568344c02271ff/vmx/migrateState/cmd/##1_50c/op/=from

Jan 21 17:00:02.746: vmx| VmxMigrateGetParam: srcIp=0xa011466 dstIp=0xa011465 mid=fcf3e205 uuid=33393935-3938-4742-4a35-35313032504d priority=high

Jan 21 17:00:02.746: vmx| MigrateSetInfo: state=7 srcIp=<10.1.20.102> dstIp=<10.1.20.101> mid=4243841541 uuid=33393935-3938-4742-4a35-35313032504d priority=high

Jan 21 17:00:02.746: vmx| MigrateStateUpdate: Transitioning from state 0 to 7.

Jan 21 17:00:02.746: vmx| Migrate: Overriding message callbacks with migration handlers.

Jan 21 17:00:02.747: vmx| PowerOn

Jan 21 17:00:02.751: vmx| VMXVmdb_LoadRawConfig: Loading raw config

Jan 21 17:00:02.783: vmx| VMMon_CreateVM: vmmon.numVCPUs=1

Jan 21 17:00:02.846: vmx| UNAME Linux esx-srv001.localdomain.com 2.4.21-47.0.1.ELvmnix #1 Thu Nov 1 19:04:45 PDT 2007 i686 (uwglibc version 4)

Jan 21 17:00:02.846: vmx| DICT --- USER PREFERENCES

Jan 21 17:00:02.846: vmx| DICT --- USER DEFAULTS

Jan 21 17:00:02.846: vmx| DICT --- HOST DEFAULTS

Jan 21 17:00:02.846: vmx| DICT libdir = /usr/lib/vmware

Jan 21 17:00:02.846: vmx| DICT authd.fullpath = /usr/sbin/vmware-authd

Jan 21 17:00:02.846: vmx| DICT authd.client.port = 902

Jan 21 17:00:02.846: vmx| DICT vmware.fullpath = /usr/bin/vmware

Jan 21 17:00:02.846: vmx| DICT control.fullpath = /usr/bin/vmware-cmd

Jan 21 17:00:02.846: vmx| DICT serverd.fullpath = /usr/sbin/vmware-serverd

Jan 21 17:00:02.846: vmx| DICT serverd.init.fullpath = /usr/lib/vmware/serverd/init.pl

Jan 21 17:00:02.846: vmx| DICT authd.proxy.vim = vmware-hostd:hostd-vmdb

Jan 21 17:00:02.846: vmx| DICT authd.proxy.nfc = vmware-hostd:ha-nfc

Jan 21 17:00:02.846: vmx| DICT --- SITE DEFAULTS

Jan 21 17:00:02.846: vmx| DICT tag.help = introduction.htm

Jan 21 17:00:02.846: vmx| DICT tag.configurationEditor = config_editor_newvm.htm

Jan 21 17:00:02.846: vmx| DICT tag.ideConfig = devices_virtualdrive.htm

Jan 21 17:00:02.846: vmx| DICT tag.floppyConfig = devices_floppy.htm

Jan 21 17:00:02.846: vmx| DICT tag.mouseConfig = devices_mouse.htm

Jan 21 17:00:02.846: vmx| DICT tag.netConfig = devices_netadapter.htm

Jan 21 17:00:02.846: vmx| DICT tag.parallelConfig = devices_parallel.htm

Jan 21 17:00:02.846: vmx| DICT tag.serialConfig = devices_serial.htm

Jan 21 17:00:02.846: vmx| DICT tag.soundConfig = devices_sound.htm

Jan 21 17:00:02.846: vmx| DICT tag.memConfig = configvm_memory.htm

Jan 21 17:00:02.846: vmx| DICT tag.miscConfig = configvm.htm

Jan 21 17:00:02.846: vmx| DICT tag.usbConfig = devices_usb.htm

Jan 21 17:00:02.846: vmx| DICT tag.displayConfig = configvm_display-problems.htm

Jan 21 17:00:02.846: vmx| DICT tag.tools = vmtools.htm

Jan 21 17:00:02.847: vmx| DICT --- COMMAND LINE

Jan 21 17:00:02.847: vmx| DICT sched.group = host/user

Jan 21 17:00:02.847: vmx| DICT --- CONFIGURATION

Jan 21 17:00:02.847: vmx| DICT config.version = 8

Jan 21 17:00:02.847: vmx| DICT virtualHW.version = 4

Jan 21 17:00:02.847: vmx| DICT floppy0.present = TRUE

Jan 21 17:00:02.847: vmx| DICT nvram = serverSRV005.nvram

Jan 21 17:00:02.847: vmx| DICT powerType.powerOff = default

Jan 21 17:00:02.847: vmx| DICT powerType.powerOn = default

Jan 21 17:00:02.847: vmx| DICT powerType.suspend = default

Jan 21 17:00:02.847: vmx| DICT powerType.reset = default

Jan 21 17:00:02.847: vmx| DICT displayName = serverSRV005

Jan 21 17:00:02.847: vmx| DICT extendedConfigFile = serverSRV005.vmxf

Jan 21 17:00:02.847: vmx| DICT scsi0.present = TRUE

Jan 21 17:00:02.847: vmx| DICT scsi0.sharedBus = none

Jan 21 17:00:02.847: vmx| DICT memsize = 128

Jan 21 17:00:02.847: vmx| DICT scsi0:0.present = TRUE

Jan 21 17:00:02.847: vmx| DICT scsi0:0.fileName = serverSRV005.vmdk

Jan 21 17:00:02.847: vmx| DICT scsi0:0.deviceType = scsi-hardDisk

Jan 21 17:00:02.847: vmx| DICT ide0:0.present = TRUE

Jan 21 17:00:02.847: vmx| DICT ide0:0.fileName = /dev/cdrom

Jan 21 17:00:02.847: vmx| DICT ide0:0.deviceType = atapi-cdrom

Jan 21 17:00:02.847: vmx| DICT floppy0.fileName = /dev/fd0

Jan 21 17:00:02.847: vmx| DICT ethernet0.present = TRUE

Jan 21 17:00:02.847: vmx| DICT ethernet0.wakeOnPcktRcv = FALSE

Jan 21 17:00:02.847: vmx| DICT ethernet0.networkName = VLAN24

Jan 21 17:00:02.847: vmx| DICT ethernet0.addressType = vpx

Jan 21 17:00:02.847: vmx| DICT ethernet0.generatedAddress = 00:50:56:b0:10:07

Jan 21 17:00:02.847: vmx| DICT guestOS = winnetstandard

Jan 21 17:00:02.847: vmx| DICT uuid.bios = 50 30 f4 8d 12 6f 76 95-1a 81 bf 84 8a cc c4 f4

Jan 21 17:00:02.847: vmx| DICT log.fileName = vmware.log

Jan 21 17:00:02.847: vmx| DICT sched.cpu.min = 0

Jan 21 17:00:02.847: vmx| DICT sched.cpu.units = mhz

Jan 21 17:00:02.847: vmx| DICT sched.cpu.shares = 116

Jan 21 17:00:02.847: vmx| DICT sched.mem.minsize = 0

Jan 21 17:00:02.847: vmx| DICT sched.mem.shares = 104

Jan 21 17:00:02.847: vmx| DICT parallel0.bidirectional = false

Jan 21 17:00:02.847: vmx| DICT scsi0:0.redo =

Jan 21 17:00:02.847: vmx| DICT tools.syncTime = FALSE

Jan 21 17:00:02.847: vmx| DICT vmware.tools.requiredversion = 7202

Jan 21 17:00:02.847: vmx| DICT sched.cpu.max = 500

Jan 21 17:00:02.847: vmx| DICT sched.mem.max = 102

Jan 21 17:00:02.847: vmx| DICT uuid.location = 56 4d 12 99 93 b9 dc b2-e5 d0 e1 6b 69 28 9f e2

Jan 21 17:00:02.847: vmx| DICT sched.swap.derivedName = /vmfs/volumes/28464ebb-2b9cca5f/serverSRV005/serverSRV005-5cfcd305.vswp

Jan 21 17:00:02.847: vmx| DICT annotation = server Citrix Presentation Server

Jan 21 17:00:02.847: vmx| DICT workingDir = .

Jan 21 17:00:02.847: vmx| DICT migrate.hostlog = ./serverSRV005-2ea9d795.hlog

Jan 21 17:00:02.847: vmx| DICT config.readOnly = FALSE

Jan 21 17:00:02.847: vmx| DICT --- USER DEFAULTS

Jan 21 17:00:02.847: vmx| DICT --- HOST DEFAULTS

Jan 21 17:00:02.847: vmx| DICT libdir = /usr/lib/vmware

Jan 21 17:00:02.847: vmx| DICT authd.fullpath = /usr/sbin/vmware-authd

Jan 21 17:00:02.847: vmx| DICT authd.client.port = 902

Jan 21 17:00:02.847: vmx| DICT vmware.fullpath = /usr/bin/vmware

Jan 21 17:00:02.847: vmx| DICT control.fullpath = /usr/bin/vmware-cmd

Jan 21 17:00:02.847: vmx| DICT serverd.fullpath = /usr/sbin/vmware-serverd

Jan 21 17:00:02.847: vmx| DICT serverd.init.fullpath = /usr/lib/vmware/serverd/init.pl

Jan 21 17:00:02.847: vmx| DICT authd.proxy.vim = vmware-hostd:hostd-vmdb

Jan 21 17:00:02.847: vmx| DICT authd.proxy.nfc = vmware-hostd:ha-nfc

Jan 21 17:00:02.847: vmx| DICT --- SITE DEFAULTS

Jan 21 17:00:02.847: vmx| DICT tag.help = introduction.htm

Jan 21 17:00:02.847: vmx| DICT tag.configurationEditor = config_editor_newvm.htm

Jan 21 17:00:02.847: vmx| DICT tag.ideConfig = devices_virtualdrive.htm

Jan 21 17:00:02.847: vmx| DICT tag.floppyConfig = devices_floppy.htm

Jan 21 17:00:02.847: vmx| DICT tag.mouseConfig = devices_mouse.htm

Jan 21 17:00:02.847: vmx| DICT tag.netConfig = devices_netadapter.htm

Jan 21 17:00:02.847: vmx| DICT tag.parallelConfig = devices_parallel.htm

Jan 21 17:00:02.847: vmx| DICT tag.serialConfig = devices_serial.htm

Jan 21 17:00:02.847: vmx| DICT tag.soundConfig = devices_sound.htm

Jan 21 17:00:02.847: vmx| DICT tag.memConfig = configvm_memory.htm

Jan 21 17:00:02.847: vmx| DICT tag.miscConfig = configvm.htm

Jan 21 17:00:02.847: vmx| DICT tag.usbConfig = devices_usb.htm

Jan 21 17:00:02.847: vmx| DICT tag.displayConfig = configvm_display-problems.htm

Jan 21 17:00:02.847: vmx| DICT tag.tools = vmtools.htm

Jan 21 17:00:02.847: vmx| DICT --- GLOBAL SETTINGS

Jan 21 17:00:02.865: vmx| STATDECLGROUP stats Root "" null

Jan 21 17:00:02.868: vmx| Host CPUID features: version 0x20f12 id1.edx 0x178bfbff id1.ecx 0x1 id81.edx 0xe3d3fbff id81.ecx 0x2

Jan 21 17:00:02.868: vmx| CPU.cpuFeatures = 0xd83dffd0

Jan 21 17:00:02.868: vmx| CPUID after masking: version 0x20f12 id1.edx 0x78bbbff id1.ecx 0x1 id81.edx 0xe3d3fbff id81.ecx 0x0 id88.ecx 0x0

Jan 21 17:00:02.868: vmx| CPU.cpuFeatures = 0xd83dffd0

Jan 21 17:00:03.054: vmx| KHZEstimate 2405455

Jan 21 17:00:03.054: vmx| MHZEstimate 2405

Jan 21 17:00:03.054: vmx| NumVCPUs 1

Jan 21 17:00:03.057: vmx| UUID: location-UUID is 56 4d 04 b2 4d 71 6a de-99 39 cc d5 c1 37 38 86

Jan 21 17:00:03.058: vmx| UUID: canonical path is /vmfs/volumes/28464ebb-2b9cca5f/serverSRV005/serverSRV005.vmx

Jan 21 17:00:03.058: vmx| UUID: location-UUID is 56 4d 04 b2 4d 71 6a de-99 39 cc d5 c1 37 38 86

Jan 21 17:00:03.058: vmx| UUID: Writing uuid.location 56 4d 04 b2 4d 71 6a de-99 39 cc d5 c1 37 38 86

Jan 21 17:00:03.074: vmx| MStat: Creating Stat vm.uptime

Jan 21 17:00:03.074: vmx| MStat: Creating Stat vm.suspendTime

Jan 21 17:00:03.075: vmx| MStat: Creating Stat vm.powerOnTimeStamp

Jan 21 17:00:03.085: vmx| MigrateWaitForData: waiting for data.

Jan 21 17:00:03.085: vmx| MigrateStateUpdate: Transitioning from state 7 to 8.

Jan 21 17:00:03.595: vmx| MigrateStateUpdate: Transitioning from state 8 to 9.

Jan 21 17:00:05.679: vmx| MigrateWaitForData: Waited for 2.59 seconds.

Jan 21 17:00:05.679: vmx| MigrateStateUpdate: Transitioning from state 9 to 10.

Jan 21 17:00:05.679: vmx| DMotion not required

Jan 21 17:00:05.685: vmx| Unable to initialize swap file /vmfs/volumes/28464ebb-2b9cca5f/serverSRV005/serverSRV005-5cfcd305.vswp

Jan 21 17:00:05.685: vmx| Module Migrate power on failed.

Jan 21 17:00:05.685: vmx| VMX_PowerOn: ModuleTable_PowerOn = 0

Jan 21 17:00:05.685: vmx| MigrateStatusFailure: Unknown failure migrating from another host.

Jan 21 17:00:05.686: vmx| MigrateSetInfo: state=11 srcIp=<0.0.0.0> dstIp=<0.0.0.0> mid=0 uuid=(null) priority=(null)

Jan 21 17:00:05.686: vmx| MigrateStateUpdate: Transitioning from state 10 to 11.

Jan 21 17:00:05.686: vmx| Migrate_ClearDoneState: cleared state. State was 11.

Jan 21 17:00:05.686: vmx| MigrateStateUpdate: Transitioning from state 11 to 0.

Jan 21 17:00:06.818: vmx| vmdbPipe_Streams Couldn't read: OVL_STATUS_EOF

Jan 21 17:00:06.818: vmx| VMX idle exit

Jan 21 17:00:06.874: vmx| Flushing VMX VMDB connections

Jan 21 17:00:06.879: vmx| IPC_exit: disconnecting all threads

Jan 21 17:00:06.879: vmx| VMX exit.

[cloggs1]

Sorry I haven't responded earlier to your posting of the log files, have been away.

Have you checked this article http: //kb.vmware.com/selfservice/microsites/search.do?language=en_US&cmd=displayKC&externalId=1000082

If a virtual machine's configuration file was manually registered using /vmfs/volumes/<friendly name>/..., and if that virtual machine was later migrated using VMotion to a host where the configuration file was specified using /vmfs/volumes/<UUID>/..., the destination host cannot find and open the swap file for the virtual machine and the migration fails. Errors encountered during this failure can include error messages similar to A general System error occured: Multi-answer question encountered while resuming. Unable to proceed. or A general system error occured: Unknown failure migrating from another host.

This issue is fixed in ESX Server 3.0.2 and higher. To work around this issue in earlier versions, don't register virtual machines using friendly volume labels such as /vmfs/volumes/<friendly name>/..., and instead use only their UUIDs, /vmfs/volumes/<UUID>/.... This issue will not be encountered. For example, to register the virtual machine myvm1 using it's UUID, use the following command: # vmware-cmd -s register /vmfs/volumes/46878935-4d25dbd5-2bd9-001125a3a121/myvm1/myvm1.vmx

[steppylud]

Hi.

I have read that, and have tried using vmware-cmd again but with no resolution. The VM's are all registered in the VI Client, so not sure how it registers the name in the first place.

[fletch00]

I have an open support case on this now...I have tried the suggestions to no success so far.

[mikepodoherty]

Don't know if this will help but we experienced a similar problem with a CALRIION SAN. While the LUN ID on the SAN and the HOST LUN ID remained the same, VMware "lost" that information. As a result, we couldn't VMotion and eventually lost all access to the SAN.

The fix was for the SAN Engineer to remove the servers and represent them back to the LUN.

2 indications of the problem - ls //vmfs/volumes showed the storage within a red block and the name of the storage was flashing and when you clicked on the storage within the VIC client, you saw the / folder with no other information instead of folders for each virtual server.

HTH

Mike

[fletch00]

We resolved this - see my forum post

Basically I used a FQDN for one and not the other (and ESX hashes then are

different!)

thanks

[Cynomus]

Execute a Storage VMotion on the guest, it will cause the drives to re-register correctly.

[steppylud]

This was caused because one of the ESX servers was rebuilt the FQDN given was in uppercase, completely messed everything up. Rebuilt the server with FQDN given in lower case and all was well.