Wczoraj podczas backupu środowiska wirtualnego za pomocą Backup Exec 2012 straciłem dostęp do jednej z maszyn. Po wyłączeniu maszyny i próbie włączenia otrzymuje komunikat:
An unexpected error was received from the ESX host while powering on VM vm-604.
Reason: The file specified is not a virtual disk.
Cannot open the disk '/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000011.vmdk' or one of the snapshot disks it depends on.
Maszyna posiada 3 dyski (plik konfiguracyjny vmx załączyłem). W samym folderze znajduje się następująca lista plików (załącznik "lista_plikow").
Sprawdzając ostatni pliki vmdk "vmkfstools -q -v10 cwt-test_1-000011.vmdk" mam następujący błąd:
DISKLIB-VMFS : "./cwt-test_1-000011-delta.vmdk" : open successful (23) size = 17027072, hd = 0. Type 8
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000010-delta.vmdk" : open successful (23) size = 17027072, hd = 0. Type 8
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000009-delta.vmdk" : open successful (23) size = 249856, hd = 0. Type 8
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000008-delta.vmdk" : open successful (23) size = 17027072, hd = 0. Type 8
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000007-delta.vmdk" : open successful (23) size = 249856, hd = 0. Type 8
DISKLIB-DSCPTR: Failed to parse descriptor file in normal mode: Wrong line format.
DISKLIB-LINK : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000006.vmdk" : failed to open (The file specified is not a virtual disk).
DISKLIB-CHAIN :"cwt-test_1-000011.vmdk": Failed to open parent "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000006.vmdk": The file specified is not a virtual disk.
DISKLIB-CHAIN : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000006.vmdk" : failed to open (The parent of this virtual disk could not be opened).
DISKLIB-VMFS : "./cwt-test_1-000011-delta.vmdk" : closed.
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000010-delta.vmdk" : closed.
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000009-delta.vmdk" : closed.
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000008-delta.vmdk" : closed.
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000007-delta.vmdk" : closed.
DISKLIB-LIB : Failed to open 'cwt-test_1-000011.vmdk' with flags 0x17 The parent of this virtual disk could not be opened (23).
Failed to open 'cwt-test_1-000011.vmdk' : The parent of this virtual disk could not be opened (23).
Deskryptor pliku "cwt-test_1-000010.vmdk":
# Disk DescriptorFile
version=3
encoding="UTF-8"
CID=032e26c6
parentCID=d7aff549
isNativeSnapshot="no"
createType="vmfsSparse"
parentFileNameHint="cwt-test_1-000009.vmdk"
# Extent description
RW 251658240 VMFSSPARSE "cwt-test_1-000010-delta.vmdk"
# Change Tracking File
changeTrackPath="cwt-test_1-000010-ctk.vmdk"
# The Disk Data Base
#DDB
ddb.longContentID = "e99acb23ae8ca82f9c5ec322032e26c6"
ddb.deletable = "true"
Deskryptor pliku "cwt-test_1-000011.vmdk":
# Disk DescriptorFile
version=3
encoding="UTF-8"
CID=808f3341
parentCID=032e26c6
isNativeSnapshot="no"
createType="vmfsSparse"
parentFileNameHint="cwt-test_1-000010.vmdk"
# Extent description
RW 251658240 VMFSSPARSE "cwt-test_1-000011-delta.vmdk"
# Change Tracking File
changeTrackPath="cwt-test_1-000011-ctk.vmdk"
# The Disk Data Base
#DDB
ddb.longContentID = "81d24c35d785f802448e720a808f3341"
vmware -v -> VMware ESXi 5.0.0 build-623860
Czy ktoś może spotkał się z takim zachowaniem vSphere5?
na jednej sesji ssh czytac
tail -f /var/log/hostd.log
na drugiej sesji robic snapshota moze byc z konsoli czy z vi clienta.
Wtedy wywali do loga barzdiej sensowny blad. i wtym bledzie bedzie ze po prostu deskryptor pliku jest uszkodzony
"
12:30 <kinimod> vmkfstools -q -v10 cwt-test_1-000010.vmdk
12:30 <kinimod> DISKLIB-VMFS : "./cwt-test_1-000010-delta.vmdk" : open successful (23) size = 17027072, hd = 0. Type 8
12:30 <kinimod> DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000009-delta.vmdk" : open successful
(23) size = 249856, hd = 0. Type 8
12:30 <kinimod> DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000008-delta.vmdk" : open successful
(23) size = 17027072, hd = 0. Type 8
12:30 <kinimod> DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000007-delta.vmdk" : open successful
(23) size = 249856, hd = 0. Type 8
12:30 <kinimod> DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000006-delta.vmdk" : open successful
(23) size = 335794176, hd = 0. Type 8
12:30 <kinimod> DISKLIB-DSCPTR: Failed to parse descriptor file in normal mode: Wrong line format.
12:30 <kinimod> DISKLIB-LINK : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000005.vmdk" : failed to open (The
file specified is not a virtual disk).
12:31 <kinimod> DISKLIB-CHAIN :"cwt-test_1-000010.vmdk": Failed to open parent
"/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000005.vmdk": The file specified is not a virtual
disk.
"
I tam byl prolem jak przegladalem jego deskryptory ze rozwalona jest linia
ddb.longContentID = "d2824c8a93c
w taki sposob
no i zauwazylem ze cos tu jest nie tak po pierwsze to jest za krotkie ID, a po drugie nawet nie ma konczacego " w tej lini. Po zglebieniu tematu , vmware mowi ze mozna nawet ominac ta linie jak cos jest nie tak. Wiec tak tez zasugerowalem.
Wszystki deskryptory z wadliwymi liniami ddb.longContentID zostaly usuniete. W sensnie linie te zostaly usuniete z deskryptorow
i potem jeszcze raz na wszystko zostal zrobiony nowy snapshot, zostalo sprawdzony czy chain jest wporzadku, i nowy snapshot mial nawiazanie do ostatniego snapshota. I potem (nie wiem ile godzin ale pewnie sporo) , zajelo juz samo kasowanie za pomoca delete all snapshotow.
Maszyna wstala i ma sie dobrze Mam nadzieje ze autor watku moze troche lepiej napisze w kwestii wyjasnienia , bo juz tyle sposob probowalismy ze ho ho
Pozdrawiam i ciesze sie ze udalo sie poradzic z maszynka
Ps. Byloby tez fajine jakby autor watku zrobil z tego jakas 'relacje' co by dla reszty bylo w razie czego pomocniejsze, mozemy nawet gzdies o tym blognac za zgoda autora
Skupiłbym się na pliku deskryptorze 00006 delta dysku. Wklej go tutaj jak i 00007 i 00005
Tam pojawia sie jakiś błąd w parsowaniu pliku (być może jakieś dziwne wpisy w środku)
Warto też porównac czy parendCID w 00007 jest równy CID z 00006
Czasami mi sie zdarzyło, że deskryptory się rozpadły przy vmotion, ale to żadkość.
Pozdrawiam
cat cwt-test_1-000005.vmdk
# Disk DescriptorFile
version=3
encoding="UTF-8"
CID=7cf7fdcd
parentCID=05a0c93d
isNativeSnapshot="no"
createType="vmfsSparse"
parentFileNameHint="cwt-test_1-000004.vmdk"
# Extent description
RW 251658240 VMFSSPARSE "cwt-test_1-000005-delta.vmdk"
# Change Tracking File
changeTrackPath="cwt-test_1-000005-ctk.vmdk"
# The Disk Data Base
#DDB
ddb.deletable = "true"
ddb.longContentID = "c3c79b15816
cat cwt-test_1-000006.vmdk
# Disk DescriptorFile
version=3
encoding="UTF-8"
CID=66b9b9d1
parentCID=7cf7fdcd
isNativeSnapshot="no"
createType="vmfsSparse"
parentFileNameHint="cwt-test_1-000005.vmdk"
# Extent description
RW 251658240 VMFSSPARSE "cwt-test_1-000006-delta.vmdk"
# Change Tracking File
changeTrackPath="cwt-test_1-000006-ctk.vmdk"
# The Disk Data Base
#DDB
ddb.deletable = "true"
ddb.longContentID = "59b7f9e9396
cat cwt-test_1-000007.vmdk
# Disk DescriptorFile
version=3
encoding="UTF-8"
CID=57e0ba09
parentCID=66b9b9d1
isNativeSnapshot="no"
createType="vmfsSparse"
parentFileNameHint="cwt-test_1-000006.vmdk"
# Extent description
RW 251658240 VMFSSPARSE "cwt-test_1-000007-delta.vmdk"
# Change Tracking File
changeTrackPath="cwt-test_1-000007-ctk.vmdk"
# The Disk Data Base
#DDB
ddb.longContentID = "e70c67110fe90ba6d668256157e0ba09"
nic nie widać na pierwszy rzut oka. Przyczepiłbym się tego pliku 00006. Może skopiować go na bok i utworzyc ręcznie jeszcze raz z tymi samymi wpisami. Jakby coś tam było, co nei pozwwala mu go przeczytać ...
na jednej sesji ssh czytac
tail -f /var/log/hostd.log
na drugiej sesji robic snapshota moze byc z konsoli czy z vi clienta.
Wtedy wywali do loga barzdiej sensowny blad. i wtym bledzie bedzie ze po prostu deskryptor pliku jest uszkodzony
"
12:30 <kinimod> vmkfstools -q -v10 cwt-test_1-000010.vmdk
12:30 <kinimod> DISKLIB-VMFS : "./cwt-test_1-000010-delta.vmdk" : open successful (23) size = 17027072, hd = 0. Type 8
12:30 <kinimod> DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000009-delta.vmdk" : open successful
(23) size = 249856, hd = 0. Type 8
12:30 <kinimod> DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000008-delta.vmdk" : open successful
(23) size = 17027072, hd = 0. Type 8
12:30 <kinimod> DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000007-delta.vmdk" : open successful
(23) size = 249856, hd = 0. Type 8
12:30 <kinimod> DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000006-delta.vmdk" : open successful
(23) size = 335794176, hd = 0. Type 8
12:30 <kinimod> DISKLIB-DSCPTR: Failed to parse descriptor file in normal mode: Wrong line format.
12:30 <kinimod> DISKLIB-LINK : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000005.vmdk" : failed to open (The
file specified is not a virtual disk).
12:31 <kinimod> DISKLIB-CHAIN :"cwt-test_1-000010.vmdk": Failed to open parent
"/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000005.vmdk": The file specified is not a virtual
disk.
"
I tam byl prolem jak przegladalem jego deskryptory ze rozwalona jest linia
ddb.longContentID = "d2824c8a93c
w taki sposob
no i zauwazylem ze cos tu jest nie tak po pierwsze to jest za krotkie ID, a po drugie nawet nie ma konczacego " w tej lini. Po zglebieniu tematu , vmware mowi ze mozna nawet ominac ta linie jak cos jest nie tak. Wiec tak tez zasugerowalem.
Wszystki deskryptory z wadliwymi liniami ddb.longContentID zostaly usuniete. W sensnie linie te zostaly usuniete z deskryptorow
i potem jeszcze raz na wszystko zostal zrobiony nowy snapshot, zostalo sprawdzony czy chain jest wporzadku, i nowy snapshot mial nawiazanie do ostatniego snapshota. I potem (nie wiem ile godzin ale pewnie sporo) , zajelo juz samo kasowanie za pomoca delete all snapshotow.
Maszyna wstala i ma sie dobrze Mam nadzieje ze autor watku moze troche lepiej napisze w kwestii wyjasnienia , bo juz tyle sposob probowalismy ze ho ho
Pozdrawiam i ciesze sie ze udalo sie poradzic z maszynka
Ps. Byloby tez fajine jakby autor watku zrobil z tego jakas 'relacje' co by dla reszty bylo w razie czego pomocniejsze, mozemy nawet gzdies o tym blognac za zgoda autora
W wolnej chwili opisze całą sytuację, jeszcze raz wielkie dzięki za zainteresowanie.
Postaram się opisać trochę bardziej szczegółowo mój problem, który został rozwiązany dzięki pomocy Grzesiekk
Do backupu używam BE2012, raz w tygodniu wykonuję pełny backup maszyn, a codzinnie w nocy backup przyrostowy. Rano w poniedziałek pojawił się problem z dostępnością jednej z maszyn zgłosił mój system monitoringu.
Kolejnym krokiem był restart vm i niestety, ale podczas startu pojawił się błąd:
"An unexpected error was received from the ESX host while powering on VM vm-604.
Reason: The file specified is not a virtual disk.
Cannot open the disk '/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000011.vmdk' or one of the snapshot disks it depends on."
Z faktu, że maszyna posiada 3 wirtualne dyski przystąpiłem do sprawdzenia, który dokładnie ma problem. W międzyczasie nie fortunnie z poziomu VC usnięte zostały snapshoty tej maszyny, kiedy była w stanie "Power Off". Niestety dalej maszyna nie chciala się podnieść. Przy próbie skopiowania dysku oznaczonego jako "cwt_test_1-(....).vmdk" otrzymwałem komunikat o locku, jednak, takowego nie było widać w plikach na datastore oraz w procesach na hoście ESXi.
Próby usuwania dysku z konfiguracji maszyny i dodawanie na nowo nic nie dawały, również przemigrowanie maszynek z hosta esxi i restart fizycznej maszyny nie pomógł (akurat tutaj to był zły trop, no ale sugerowałem się, że może...).
W oknie managera snapshotów VC tej maszyny nic nie było, czyli brak snapshotów, jednak w folderze z maszynami uszkodzony dysk posiadał ich 11. Pozostałe 2 dyski wirtualne również miały kilka.
Przy sprawdzeniu chain'a dla dysku "cwt-test_1-000011.vmdk" pojawił się błąd:
Sprawdzając ostatni pliki vmdk "vmkfstools -q -v10 cwt-test_1-000011.vmdk" mam następujący błąd:
DISKLIB-VMFS : "./cwt-test_1-000011-delta.vmdk" : open successful (23) size = 17027072, hd = 0. Type 8
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000010-delta.vmdk" : open successful (23) size = 17027072, hd = 0. Type 8
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000009-delta.vmdk" : open successful (23) size = 249856, hd = 0. Type 8
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000008-delta.vmdk" : open successful (23) size = 17027072, hd = 0. Type 8
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000007-delta.vmdk" : open successful (23) size = 249856, hd = 0. Type 8
DISKLIB-DSCPTR: Failed to parse descriptor file in normal mode: Wrong line format.
DISKLIB-LINK : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000006.vmdk" : failed to open (The file specified is not a virtual disk).
DISKLIB-CHAIN :"cwt-test_1-000011.vmdk": Failed to open parent "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000006.vmdk": The file specified is not a virtual disk.
DISKLIB-CHAIN : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000006.vmdk" : failed to open (The parent of this virtual disk could not be opened).
DISKLIB-VMFS : "./cwt-test_1-000011-delta.vmdk" : closed.
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000010-delta.vmdk" : closed.
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000009-delta.vmdk" : closed.
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000008-delta.vmdk" : closed.
DISKLIB-VMFS : "/vmfs/volumes/4f141d57-267ffa9c-f714-001999b9a96c/cwt_1/cwt-test_1-000007-delta.vmdk" : closed.
DISKLIB-LIB : Failed to open 'cwt-test_1-000011.vmdk' with flags 0x17 The parent of this virtual disk could not be opened (23).
Failed to open 'cwt-test_1-000011.vmdk' : The parent of this virtual disk could not be opened (23).
Podjeliśmy próbę zmergowania wszystkich niewidocznych snapshotów z poziomu managera za pomocą procedury:
1. vim-cmd vmsvc/getallvms - Command to Get VM ID 2. vim-cmd vmsvc/snapshot.get [VMID] - Command to see what Snapshot the VM has 3. vim-cmd vmsvc/snapshot.create [VmId] [snapshotName] 0 0 0 - Create a Snapshot 4. vim-cmd vmsvc/snapshot.removeall [VmId] - Remove Snapshot <BR><BR>
i w trakcie tworzenia snapshotu obserwowaliśmy "hostd.log" - podobne logi do polecenia vmkfstools pojawiły się w nim.
Po porównaniu deskryptorów wszytkich plików cwt-test_1-*.vmdk okazało się, że pliki o numerach 6,5,4 mają uciętą wartość parametru "ddb.longContentID", poniżej przykładowy mój plik, który został ucięty:
(...)
# The Disk Data Base
#DDB
ddb.deletable = "true"
ddb.longContentID = "c3c79b15816 <-- tutaj brakuje dokończonego identyfikatora
W przypadku dobrych plików sekcja ta wygląda następująco:
# The Disk Data Base
#DDB
ddb.longContentID = "e70c67110fe90ba6d668256157e0ba09" <-- prawidłowa linia
Zabraliśmy na warsztat deskryptory vmdk o numerach 6,5,4 i w każdym z nich usunęliśmy ostatnią (uciętą) linię.
Po tej operacji i ponownej weryfikacji chain'a za pomocą "vmkfstools -q" wszystko zaczęło działać prawidłowo i mogłem wykonać do końca procedurę mergowania snapshiotów:
1. vim-cmd vmsvc/snapshot.create [VmId] [snapshotName] 0 0 0 - Create a Snapshot 2. vim-cmd vmsvc/snapshot.removeall [VmId] - Remove Snapshot <BR><BR>
Operacja mergowania trwała około 3 godziny i po tym wszystkim maszyna została uruchomiona z sukcesem 🙂
Tak na szybko okazało się jeszcze, że ten cały bajzel z taką ilością plików snapshot powoduje BE2012, jak tylko zweryfikuję dlaczego tak się zachowuje w przypadku maszyn virtualnych z systemami linux (z windowsami działa prawidłowo). Jak tylko dowiem się, co można z tym zrobić, aby sytuacja nie miała miejsca napiszę w kolejnym komentarzu.
P.S Mam nadzieję, że w miarę czytelnie napisałem, może mało technicznie, jakby potrzebne były wyjaśnienia to proszę o komentarz.
awesome!