Search the VMware Knowledge Base (KB)
View by Article ID

vMotion が 14% の時点で失敗し、次のエラーが表示される: 移行開始要求の待機中にタイム アウトになりました (2069351)

  • 0 Ratings

Symptoms

免責事項:これは英文の記事 「vMotion fails at 14% with the error : Timed out waiting for migration start request (2068817)」の日本語訳です。記事はベストエフォートで翻訳を進めているため、ローカライズ化コンテンツは最新情報ではない可能性があります。最新情報は英語版の記事で参照してください。
  • 仮想マシンの vMotion を実行すると、次のエラーで失敗する。

    Timed out waiting for migration start request

    The operation is not allowed in the current state

  • /var/log/ にある hostd.log ファイルに、次のようなエントリが出力される。

    YYYY-MM-DDT18:05:57.413Z [3E057B90 info 'vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Disconnect check in progress.
    YYYY-MM-DDT18:05:57.413Z [3DF03B90 verbose 'Vmsvc.vm://vmfs/volumes/datastorename/VM1/VM1.vmx'] VMotionLastStatusCb: Failed with error 4: Timed out waiting for migration start request.

    YYYY-MM-DDT18:05:57.424Z [3DF03B90 info 'Hostsvc.HaHost'] vmxSwapEnabled = true vmmOvhd.anonymous: 22964 vmmOvhd.paged: 63957 vmmOvhd.nonpaged: 13771
    YYYY-MM-DDT18:05:57.424Z [3DF03B90 info 'Hostsvc.HaHost'] vmkOvhd.fixd = 303104 vmkOvhd.variable: 2050 vmkOvhd.selfSwap: 3145728
    YYYY-MM-DDT18:05:57.424Z [3DF03B90 info 'Hostsvc.HaHost'] Computed from lib overhead: 150466560 for (memPages: 524288, fbSize: 2048, #vcpus: 2, #lsiscsi: 1, #pvscsi: 0, #passthru: 0, #network: 1) vmkOverhead: 7647232
    YYYY-MM-DDT18:05:57.424Z [3DF03B90 info 'Hostsvc.HaHost'] overhead result (no CBRC): 158113792
    YYYY-MM-DDT18:05:57.424Z [3DF03B90 info 'Hostsvc.HaHost'] Predicted overhead: 158113792 for (memory: 2147483648, video: 8388608, #vcpus: 2, autodetect: false, enable3D: false, svgaPtFbSize: 8388608, cbrcOverhead: 0
    YYYY-MM-DDT18:05:57.424Z [3DF03B90 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Time to gather config: 11 (msecs)
    YYYY-MM-DDT18:05:57.425Z [3DF44B90 verbose 'Hbrsvc'] Replicator: ReconfigListener triggered for config VM 44
    YYYY-MM-DDT18:05:57.431Z [3DF03B90 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] VMotionLastStatusCb:: hostlog state changed from emigrating to failure
    YYYY-MM-DDT18:05:57.431Z [3DF03B90 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] VMotionResolveCheck: Operation in progress
    YYYY-MM-DDT18:05:57.431Z [3DF44B90 verbose 'Hbrsvc'] Replicator: VmReconfig ignoring VM 44 not configured for replication
    YYYY-MM-DDT18:05:57.432Z [3DF44B90 info 'Snmpsvc'] VmConfigListener: vm state change received, queueing reload request
    YYYY-MM-DDT18:05:57.433Z [3E1DCB90 warning 'Default'] Can't convert IP Address of type 0
    YYYY-MM-DDT18:05:57.433Z [3DF03B90 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] VMotionStatusCb: Completed
    YYYY-MM-DDT18:05:57.433Z [3DF03B90 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] VMotionResolveCheck: Firing ResolveCb
    YYYY-MM-DDT18:05:57.433Z [3DF03B90 info 'Vcsvc.VMotionSrc (1388772268136447)'] ResolveCb: VMX reports needsUnregister = false for migrateType MIGRATE_TYPE_VMOTION
    YYYY-MM-DDT18:05:57.433Z [3DF03B90 info 'Vcsvc.VMotionSrc (1388772268136447)'] ResolveCb: Failed with fault: (vmodl.fault.SystemError) {
        dynamicType = <unset>,
        faultCause = (vmodl.MethodFault) null,
        reason = "Timed out waiting for migration start request.
    ",
        msg = "",
    }

  • /var/log/ にある hostd.log ファイルに、次のようなエントリが出力される。

    YYYY-MM-DDT18:04:27.536Z [4FA40B70 info 'Vcsvc.VMotion' opID=57C757C9-000004C9-9c-75-89 user=vpxuser] InitiateDestination [1388772268136447], VM = '/vmfs/volumes/datastorename/VM1/VM1.vmx'
    YYYY-MM-DDT18:04:27.536Z [4FA40B70 info 'Vimsvc.TaskManager' opID=57C757C9-000004C9-9c-75-89 user=vpxuser] Task Created : haTask-ha-folder-vm-vim.Folder.registerVm-95992205
    YYYY-MM-DDT18:04:27.536Z [4FA40B70 info 'Solo.HaVMFolder' opID=57C757C9-000004C9-9c-75-89 user=vpxuser] Register called: []/vmfs/volumes/datastorename/VM1/VM1.vmx
    YYYY-MM-DDT18:04:27.544Z [4E040B70 verbose 'Default' opID=9348D6C9-0000017D user=root] AdapterServer: target='vmodl.query.PropertyCollector:ha-property-collector', method='waitForUpdates'
    YYYY-MM-DDT18:04:27.647Z [4FA40B70 verbose 'Vmsvc' opID=57C757C9-000004C9-9c-75-89 user=vpxuser] Queued registering virtual machine /vmfs/volumes/datastorename/VM1/VM1.vmx
    YYYY-MM-DDT18:04:27.647Z [4E040B70 verbose 'Vmsvc'] Initializing registering virtual machine [51]: /vmfs/volumes/datastorename/VM1/VM1.vmx

    YYYY-MM-DDT18:04:27.650Z [4E040B70 info 'vm:Vix: [34103 foundryPollWorker.c:624]: FoundryPollWorker_AssignVMToWorker: Assign VM:/vmfs/volumes/datastorename/VM1/VM1.vmx'] to worker 4E640B70.
    YYYY-MM-DDT18:04:27.653Z [4E640B70 info 'vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Reloading config state.
    YYYY-MM-DDT18:04:27.668Z [4E640B70 info 'Libs'] VMHS: Transitioned vmx/execState/val to poweredOff
    YYYY-MM-DDT18:04:27.693Z [4E040B70 verbose 'Default'] SetVmHandle /vmfs/volumes/datastorename/VM1/VM1.vmx 3145898
    YYYY-MM-DDT18:04:27.693Z [4E040B70 info 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Upgrade is required for virtual machine, version: 7
    YYYY-MM-DDT18:04:27.694Z [4E040B70 info 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Snapshot tree refresh ignored because the disk access is not enabled.
    YYYY-MM-DDT18:04:27.695Z [4E040B70 warning 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] PopulateCache failed: _diskAccess : false, _storageAccessible : true
    YYYY-MM-DDT18:04:27.696Z [4E040B70 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Get shared vigor fields translated error to vim.fault.GenericVmConfigFault
    YYYY-MM-DDT18:04:27.696Z [4E040B70 info 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Get shared vigor fields failed: vim.fault.GenericVmConfigFault
    YYYY-MM-DDT18:04:27.696Z [4E040B70 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Get shared vigor fields message: CPUID register value () is invalid.
    CPUID register value () is invalid.
    CPUID register value () is invalid.
    CPUID register value () is invalid.
    YYYY-MM-DDT18:04:27.696Z [4E040B70 info 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Error encountered while retrieving configuration. Marking configuration as invalid: vim.fault.GenericVmConfigFault
    YYYY-MM-DDT18:04:27.696Z [4E040B70 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Fault Tolerance state callback received
    YYYY-MM-DDT18:04:27.696Z [4E040B70 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Record/replay state callback received
    YYYY-MM-DDT18:04:27.696Z [4E040B70 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Skipped tools version initialization as the VM's disk access is not enabled
    YYYY-MM-DDT18:04:27.697Z [4E040B70 info 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] State Transition (VM_STATE_INITIALIZING -> VM_STATE_OFF)
    YYYY-MM-DDT18:04:27.697Z [4E040B70 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Max connection count changed from 0 to 40
    YYYY-MM-DDT18:04:27.698Z [4E040B70 info 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Initialized virtual machine.
    YYYY-MM-DDT18:04:27.701Z [4E040B70 info 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] Marking VirtualMachine invalid
    YYYY-MM-DDT18:04:27.701Z [4E040B70 info 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx'] State Transition (VM_STATE_OFF -> VM_STATE_INVALID_CONFIG)
    YYYY-MM-DDT18:04:27.701Z [4E040B70 verbose 'Hostsvc.HostConfigSyncManagerImpl'] Sync called
    YYYY-MM-DDT18:04:27.701Z [4E040B70 verbose 'Hostsvc.HostConfigSyncManagerImpl'] Scheduling '/sbin/backup.sh' in 5 seconds (backup counter = 0)
    YYYY-MM-DDT18:04:27.702Z [4E040B70 verbose 'Hostsvc.ResourcePool ha-root-pool'] Added child 51 to pool
    YYYY-MM-DDT18:04:27.702Z [4E040B70 info 'Vimsvc.ha-eventmgr'] Event 250 : Registered Unknown 36 on mtaspesx4.mta.mdot.mdstate in ha-datacenter
    YYYY-MM-DDT18:04:27.702Z [4E040B70 warning 'Default'] Complete Task: task haTask-ha-folder-vm-vim.Folder.registerVm-95992205 not registered as started
    YYYY-MM-DDT18:04:27.702Z [4E040B70 info 'Vimsvc.TaskManager'] Task Completed : haTask-ha-folder-vm-vim.Folder.registerVm-95992205 Status success
    YYYY-MM-DDT18:04:27.708Z [FFD5BB70 verbose 'Default' opID=9348D6C9-0000017E user=root] AdapterServer: target='vmodl.query.PropertyCollector:session[43831e05-bc42-7082-620c-a24c0da54260]5268e62e-6cca-eab7-117e-ea9b8e05dd4a', method='waitForUpdates'
    YYYY-MM-DDT18:04:27.710Z [4F780B70 verbose 'Default' opID=SWI-bfd8bde9 user=vpxuser] AdapterServer: target='vim.ResourcePool:ha-root-pool', method='GetConfig'
    YYYY-MM-DDT18:04:27.712Z [4E040B70 verbose 'Default' opID=SWI-bfd8bde9 user=vpxuser] AdapterServer: target='vim.ResourcePool:ha-root-pool', method='GetName'
    YYYY-MM-DDT18:04:27.748Z [4FA40B70 error 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx' opID=57C757C9-000004C9-9c-75-89 user=vpxuser] Invalid transition requested (VM_STATE_INVALID_CONFIG -> VM_STATE_IMMIGRATING): Invalid state
    YYYY-MM-DDT18:04:27.748Z [4FA40B70 warning 'Vcsvc.VMotionDst (1388772268136447)' opID=57C757C9-000004C9-9c-75-89 user=vpxuser] Bind: Failed to initialize VMotionWorker
    YYYY-MM-DDT18:04:27.748Z [4FA40B70 warning 'Vcsvc.VMotionDst (1388772268136447)' opID=57C757C9-000004C9-9c-75-89 user=vpxuser] Initiate: Bind failed: vim.fault.InvalidState
    YYYY-MM-DDT18:04:27.748Z [4FA40B70 warning 'Vcsvc.VMotionDst (1388772268136447)' opID=57C757C9-000004C9-9c-75-89 user=vpxuser] Initiate: Unregistering after Bind failure
    YYYY-MM-DDT18:04:27.748Z [4FA40B70 verbose 'Vmsvc.vm:/vmfs/volumes/datastorename/VM1/VM1.vmx' opID=57C757C9-000004C9-9c-75-89 user=vpxuser] Unregister called on virtual machine

Cause

この問題は、vMotion される仮想マシンの .vmx ファイルの cpuid 値が見つからないために発生します。

Resolution

この問題は、ESXi 5.5 Update 2 で解決されており、「VMware Downloads」から入手できます。 詳細については、『VMware ESXi 5.5 Update 2 Release Notes』を参照してください。

問題を回避するには、次の手順を実行します。
  1. .vmx ファイル cp path/filename path/filename.bak のバックアップを作成します。

    path はファイルのフルパス、filename は編集するファイルの名前です。

    cp コマンドの 2 つめのパラメータは、バックアップ コピーであることを示す .bak 拡張子が付いたファイル名を持ちます。

  2. .vmx ファイル内で、値が空白になっている cpuid エントリを探します。 例:

    cpuid.X.eax = ""
    cpuid.X.ecx = ""
    cpuid.X.ecx.amd = ""
    cpuid.X.edx = ""


    X は有効な数値を表わします。

  3. マシンをパワーオフします。
  4. テキスト エディタを使用し、.vmx ファイルからこれらのエントリを削除します。 詳細については、「ESX ホスト上で vi または nano を使用してファイルを編集する (2092665)」を参照してください。
  5. 仮想マシンを再ロードします。 詳細については、「インベントリから仮想マシンを削除せずに vmx ファイルをリロードする (2090096)」を参照してください。 または、マシンを登録解除してから再度登録します。
  6. 仮想マシンをパワーオンします。
  7. .vmx ファイル内から cpuid のエントリが削除されたことを確認します。
  8. パワーオンしたマシンの vMotion を再度実行します。

Impact/Risks

  • .vmx ファイルに変更を加える際、仮想マシンはパワーオフされている必要があります。
  • マシンをパワーオフし、コールドマイグレーションを実行することは可能です。しかし、ファイルを変更しない限り vMotion は常に失敗します。
  • ファイルを編集して、仮想マシンをパワーオフせずにフリロードすると、リロード後の .vmx ファイルに空白のエントリが再度作成されてしまいます。
  • .vmx ファイルは今後のマイグレーションを正常に実行するために編集しておく必要があり、この変更を反映するために一時的に仮想マシンをパワーオフする必要があります。

Tags

日本語 Japanese

See Also

Request a Product Feature

To request a new product feature or to provide feedback on a VMware product, please visit the Request a Product Feature page.

Feedback

  • 0 Ratings

Did this article help you?
This article resolved my issue.
This article did not resolve my issue.
This article helped but additional information was required to resolve my issue.

What can we do to improve this information? (4000 or fewer characters)




Please enter the Captcha code before clicking Submit.
  • 0 Ratings
Actions
KB: