VMware 妙妙妙 - Migrate VM Storage vMotion 發生無法理解的錯誤

今天來回覆聽眾 Mr. K 的點播。
本篇字數較多，覺得硬的話可分次閱讀。

<<前情提要>>
新機器安裝 ESXi 6.7，舊機器原先安裝 ESXi 6.5，新環境佈署 VCSA 6.7，並將所有 ESXi Host 加入管理。在 vSphere HTML5 Client 下操作，所有的 VM 都是放在 Local Datastore 下，將原先在 6.5 的開機的 VM Migrate 到 6.7 沒問題，但要從 6.7 將開機的 VM Migrate 到 6.5 無法成功。
在執行 vMotion+Storage vMotion 時，過程的結尾會發生奇妙的錯誤：The backing path name is invalid. (中文版 Web Client 看到的訊息是：支援路徑名稱無效)

題外話：VMware vSphere 6.7 在 17 APR 2018 低調現身，殺個讓人措手不及，後續有空再來分享 What's new in vSphere 6.7。

<<解題無腦版>>
一般用關鍵字呼叫咕狗，通常第一頁就會有 VMware KB (Knowledge Base) 出來解危，當然 KB 不是一定有用，但至少會有些解謎方向，但這次卻完全沒有相關資料。

嘗試了幾個...沒啥用的方法，像是：
(1)檢查 Virtual Machine Hardware Version，是否不小心按到升級為 ESXi 6.5 不支援的更高版本。
(2)檢查是否有隱藏未刪除乾淨的 snapshot。
(3)將這個 VM → Remove from inventory → Add to inventory。
(4)...
大概還有十八招，不過既然沒用就不用全部寫出來了，以免誤人子弟。

<<解題認真版>>
VM 在 power on 的時候作 vMotion+Storage vMotion，會牽涉到兩端 Host 的 CPU 相容性 (如果主機型號不同，造成 CPU 世代差異，而且又沒有開啟 EVC 的話)，所以先問 VM 能否 shutdown，關機後再做 VM Storage vMotion (或是應該說 change host+datastore)，這樣子就只牽涉到純資料搬移，去除硬體相容性的影響。

不過 VM shutdown 之後做 Migrate 還是老樣子，一樣失敗，一樣的錯誤訊息～沒關係只好開始土法煉鋼，開始翻各種地方的 log file，查看該個 VM 的 Events 也沒有什麼幫助，只好開始繼續往 ESXi Host 挖。

小提示：可以透過 Export System Logs (Export the Support Bundle) 功能，把 ESXi Host 的各種 Log 資訊打包後下載回來，這也是開 Support Ticket 時，Support Engineer 很常叫客戶做的事情之一。將下載的壓縮檔解開後，在外面使用文字編輯器 (Notepad++, MadEdit, UltraEdit, ...) 會比較容易查看及搜尋，如果對 vi 的用法很熟悉的話，在 ESXi SSH Shell 下直接來也是可以。

順便抱怨分享另一件奇妙的事，我在 vCSA 6.7 的環境，不管是透過 Web Client 還是 vSphere HTML5 Client，都找不到 Export System Logs 的功能，不知道是位置換了還是新版本的霸格，VMware KB 的適用版本 6.7 還沒加上去，山不轉路轉，改成直接連到 ESXi Host Client 就順利的打包 Support Bundle。

關於在每台 ESXi 上 VM 的操作及詳細 log 都會儲存在每台 ESXi Host 的檔案 /var/log/hostd.log，打包出來的 support bundle 目錄結構會有些許改變，變成 /var/run/log/hostd.log。Log files 每天系統會自動 rotate，歷史檔案會壓縮起來，所以往前的歷史天數依序是：hostd.0.gz, hostd.1.gz, ... hostd.8.gz。

在轉移來源端的 hostd.log 內找不到明顯的錯誤，再來往轉移目的端的 ESXi 尋找。
(轉移目的端)節錄 esxi-target-hostd.log 一段，包含可能有問題的訊息：

2018-06-06T08:32:38.932Z info hostd[2105829] [Originator@6876 sub=Vimsvc.ha-eventmgr opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator] Event 295 : Creating ucspe-3 on host localhost.localdomain in ha-datacenter

2018-06-06T08:32:38.934Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator] FILE: FileCreateDirectoryEx: Failed to create /vmfs. Error = 17

2018-06-06T08:32:38.934Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator] FILE: FileCreateDirectoryEx: Failed to create /vmfs/volumes. Error = 17

2018-06-06T08:32:38.934Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator] FILE: FileCreateDirectoryEx: Failed to create /vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948. Error = 17

2018-06-06T08:32:38.934Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator] FILE: FileCreateDirectoryEx: Failed to create /vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3. Error = 17

2018-06-06T08:32:38.944Z info hostd[2105829] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3/ucspe-3.vmx opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator] SetVmxVersion: switching environment browser to vmx version 'vmx-13'

2018-06-06T08:32:38.952Z info hostd[2098843] [Originator@6876 sub=Snmpsvc] VmConfigListener: vm state change received, queueing reload request

2018-06-06T08:32:38.964Z info hostd[2105829] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3/ucspe-3.vmx opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator] Reconfigure failed: N3Vim5Fault20GenericVmConfigFault9ExceptionE(Fault cause: vim.fault.GenericVmConfigFault

--> )

--> [context]zKq7AVICAgAAAMKpfAAcaG9zdGQAAHyZNWxpYnZtYWNvcmUuc28AAADAGwBgsBcBv1v9bGlidmltLXR5cGVzLnNvAIFiMhYBgY6HFgGBmnUSAQK1O9hob3N0ZAAC6h3WAu0l1gLcP9YCWwixAlILsQLldLECAYquAta7tQLaxrUCiuq5AkDtuQJCb2WBomQBAQL148EC7ezBACUwKAADNCgAOw82A2uAAGxpYnB0aHJlYWQuc28uMAAE7ZoObGliYy5zby42AA==[/context]

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator] CopyFromDisk: Hostlog_Dump: Hostlog /vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3/ucspe-3-757d692b.hlog

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    UUID: 39363436-3230-4e43-3732-34323033324c

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    MigID: 7034122878062430581

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    HLState: none

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    ToFrom: none

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    MigType: invalid

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    OpType: nfc

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    WorldID: 0

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    Item Dir F "/vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3"

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    Item Disk F "/vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3/ucspe-3.vmdk"

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    Item File F "/vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3/ucspe-3.nvram"

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    Item File F "/vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3/vmware-1.log"

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Libs opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    Item File F "/vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3/vmware.log"

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=vm opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator]    Item Vm F "/vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3/ucspe-3.vmx"

2018-06-06T08:32:38.984Z info hostd[2105829] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3/ucspe-3.vmx opID=5572f059-d0d4-471b-8fe6-2674b614e9f4-192755-auto-192756-h5c:70026332-44-01-7b-7e27 user=vpxuser:VSPHERE.LOCAL\Administrator] Create failed with given spec: /vmfs/volumes/5b1735f8-10a8490f-6eae-ac162d6f9948/ucspe-3/ucspe-3.vmx

這一看就覺得事情並不單純，ucspe-03.vmx 裡面的內容肯定有鬼，到底是什麼鬼我也不知道，明明七月還沒到就跨丟。
把 ucspe-03.vmx 打開來看，我用火眼金睛看過三次之後，還是看不出哪裡有問題，去咕狗找 vmx format checker 之類的東西，也沒找到這種工具。

繼續來土法煉鋼，如果確定方向是 vmx 的內容有問題，那用 Create Virtual Machine 產生出來的 .vmx 就絕對沒問題。為了以防萬一，原先的 VMDK (Virtual Disk) 先留著，以免發生不測。
假設原先的 VM 是 ucspe-03，新的 VM 取名 ucspe-03-new，請自行依環境修改參數，大致步驟如下：
(vmkfstools 為 ESXi Shell 下指令，請自行小心使用)
(1) 複製 ucspe-03.vmdk，新的檔案 ucspe-03-new.vmdk。
vmkfstools -i ucspe-03.vmdk ucspe-03-new.vmdk
(2) 建立新的虛擬機 (Create a Virtual Machine)，名稱為 ucspe-03-new，建立 Virtual Disk 步驟請跳過暫時不要建立，其他參考原先 VM 的 Virtual Hardware 需一致。
請自行操作 Web Client 或 vSphere HTML5 Client。
(3) 將複製出來的 ucspe-03-new.vmdk，搬移到新建 VM 的目錄下 (此步驟是為了往後管理方便)。
vmkfstools -E ucspe-03-new.vmdk ../ucspe-03-new/ucspe-03-new.vmdk
(4) 將新 VM ucspe-03-new 掛上複製的 ucspe-03-new.vmdk。
請自行操作 Web Client 或 vSphere HTML5 Client。
(5) Power On 新 VM ucspe-03-new，看是否運作正常；若正常可將此 VM 關機。
(6) 對新 VM 再做一次 Migrate VM，看 Storage vMotion 搬移過程是否還有錯誤。
(7) 如果一切正常的話，可以把原先無法搬移的舊 VM 完全刪除。

打完收工！


<<參考資料>>
vSphere 6.7 Release Notes

Collecting diagnostic information for VMware ESX/ESXi (653)

vmkfstools - vSphere CLI for managing VMFS volumes.

Validating the .vmx settings of a virtual machine (1003748)

<<附檔收錄>>
這邊是 Migrate VM 的事件完整 log 檔、ucspe-03.vmx，有興趣的可以下載回去研究：
(轉移來源端) esxi-source-hostd.log
(轉移目的端) esxi-target-hostd.log
(VM設定檔) ucspe-3.vmx


〈本文同步刊載於痞客邦部落格〉

VMware 妙妙妙 - Migrate VM Storage vMotion 發生無法理解的錯誤 @ 狸貓先生愛廢話講堂 :: 痞客邦 ::