Траблшутинг операций VMware vMotion – как искать проблемы в логах при миграциях виртуальных машин.

This post was originally published on this site

Часто при миграциях vMotion виртуальной машины с одного хоста ESXi на другой возникает проблема, источник которой не очень понятен. Большинство администраторов знают основные требования vMotion, также при миграции иногда показываются информационные сообщения, отражающие причину, по которой процесс завершился неудачно.

Но такое бывает не всегда, поэтому давайте посмотрим, как правильно искать причины ошибок vMotion в логах хостов. Для начала напомним основные причины проблем с vMotion:

  • Проблемы сетевых соединений vMotion
    • Хосты ESXi не пингуются или отваливаются по таймауту в 20 секунд.
    • Несоответствие MTU между интерфейсом VMkernel и данным параметром в сети (на коммутаторах или маршрутизаторах).
    • Неправильная конфигурация сети на хостах ESXi.
  • Проблемы хранилищ
    • Целевой датастор недоступен или переведен в статус APD (All Paths Down).
    • Таймаут операций ввода-вывода (I/O) составляет 20 секунд или более.
  • Операция vMotion прошла успешно, но наблюдаются проблемы с гостевой ОС.
    • Ошибка VM network is not reachable – на уровне layer-2 нет соединения на целевом хосте ESXi.
  • Ошибки, связанные с ресурсами.
    • В течение долгого времени хост не может выделить память виртуальной машине.
    • Свопирование идет очень долго, что приводит к вываливанию vMotion по таймауту.

При траблшутинге vMotion, в первую очередь, проверьте, что в вашей инфраструктуре соблюдаются основные требования, приведенные здесь.

С точки зрения логирования процесса vMotion, он устроен следующим образом:

Из картинки видно, что 4 лог-файла можно найти на хосте ESXi и один – на сервере vCenter.

Демоны vCenter Daemon (VPXD), vCenter Agent (VPXA) и Host Daemon (hostd) – это основные службы, которые отвечают за процесс миграции vMotion, и именно там следует начинать искать проблему. Что касается компонентов, отвечающих за реализацию на стороне ВМ – это процесс VMX и службы VMkernel.

Первый шаг траблшутинга – это найти Operation ID (opID) операции vMotion в логах. Этот opID отсылает уже к нужному Migration ID на обоих хостах ESXi.

VPXD-лог на vCenter Server позволит найти opID. Для этого залогиньтесь на VCSA (vCenter Server Appliance) и выполните команду:

grep "relocate" /var/log/vmware/vpxd/vpxd-*.log | grep BEGIN

В выводе команды вы найдете нужный opID:

/var/log/vmware/vpxd/vpxd-214.log:2019-09-24T15:38:10.042Z info vpxd[29243] [Originator@6876 sub=vpxLro opID=jzlgfw8g-11824-auto-94h-h5:70003561-20] [VpxLRO] — BEGIN task-8031 — vm-269 — vim.VirtualMachine.relocate — 52b17681-35d1-998b-da39-de07b7925dda(520681db-25b7-c5d6-44d7-6a056620e043)

Далее, зная opID, вы можете найти Migration ID в hostd-логах на соответствующих хостах ESXi. Делается это следующей командой:

grep jzlgfw8g-11824-auto-94h-h5:70003561-20 /var/log/hostd.log | grep -i migrate

Исходный хост ESXi

2019-09-24T15:38:47.070Z info hostd[2100388] [Originator@6876 sub=Vcsvc.VMotionSrc.3117907752192811422 opID=jzlgfw8g-11824-auto-94h-h5:70003561-20-01-10-e036 user=vpxuser:VSPHERE.LOCALAdministrator] VMotionEntry: migrateType = 1 2019-09-24T15:38:47.072Z info hostd[2100388] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/b86202d8-fb958817-0000-000000000000/NH-DC-02/NH-DC-02.vmx opID=jzlgfw8g-11824-auto-94h-h5:70003561-20-01-10-e036 user=vpxuser:VSPHERE.LOCALAdministrator] VigorMigrateNotifyCb:: hostlog state changed from success to none

Целевой хост ESXi

2019-09-24T15:38:47.136Z info hostd[2099828] [Originator@6876 sub=Vcsvc.VMotionDst.3117907752192811422 opID=jzlgfw8g-11824-auto-94h-h5:70003561-20-01-2c-3c35 user=vpxuser:VSPHERE.LOCALAdministrator] VMotionEntry: migrateType = 1

На стороне VMkernel вы можете найти информацию о неудачной миграции следующей командой:

grep VMotion /var/log/vmkernel*

Исходный хост ESXi:

019-09-24T15:38:47.402Z cpu13:46101760)VMotionUtil: 5199: 3117907752192811422 S: Stream connection 1 added.
2019-09-24T15:38:47.445Z cpu8:46092538)XVMotion: 2062: Allocating pool 0.
2019-09-24T15:38:47.445Z cpu8:46092538)XVMotion: 642: Bitmap page: len = 16384, pgLen = 1, bitSet = 3001, bitClear = 13383.
2019-09-24T15:38:47.445Z cpu8:46092538)XVMotion: 642: Bitmap block: len = 131072, pgLen = 4, bitSet = 131072, bitClear = 0.
2019-09-24T15:38:47.445Z cpu8:46092538)VMotion: 8134: 3117907752192811422 S: Requiring explicit resume handshake.
2019-09-24T15:38:47.445Z cpu13:46101760)XVMotion: 3384: 3117907752192811422 S: Starting XVMotion stream.
2019-09-24T15:39:34.622Z cpu14:46101762)VMotion: 5426: 3117907752192811422 S: Disk copy complete, no bandwidth estimate.
2019-09-24T15:39:34.905Z cpu24:46092539)VMotion: 5281: 3117907752192811422 S: Stopping pre-copy: only 37 pages left to send, which can be sent within the switchover time goal of 0.500 seconds (network bandwidth ~185.134 MB/s, 1536000% t2d)
2019-09-24T15:39:34.965Z cpu13:46101760)VMotionSend: 5095: 3117907752192811422 S: Sent all modified pages to destination (network bandwidth ~281.100 MB/s)
2019-09-24T15:39:35.140Z cpu15:46101757)XVMotion: 642: Bitmap page: len = 16384, pgLen = 1, bitSet = 3001, bitClear = 13383.
2019-09-24T15:39:35.140Z cpu15:46101757)XVMotion: 642: Bitmap block: len = 131072, pgLen = 4, bitSet = 131072, bitClear = 0.

Целевой хост ESXi:

2019-09-24T15:38:47.397Z cpu15:2099283)VMotionUtil: 5199: 3117907752192811422 D: Stream connection 1 added.
2019-09-24T15:38:47.440Z cpu3:3543984)XVMotion: 2062: Allocating pool 0.
2019-09-24T15:38:47.440Z cpu3:3543984)XVMotion: 642: Bitmap page: len = 16384, pgLen = 1, bitSet = 3001, bitClear = 13383.
2019-09-24T15:38:47.440Z cpu3:3543984)XVMotion: 642: Bitmap block: len = 131072, pgLen = 4, bitSet = 131072, bitClear = 0.
2019-09-24T15:38:47.440Z cpu3:3543984)VMotion: 8134: 3117907752192811422 D: Requiring explicit resume handshake.
2019-09-24T15:39:34.907Z cpu3:3543984)VMotionRecv: 761: 3117907752192811422 D: Estimated network bandwidth 205.138 MB/s during pre-copy
2019-09-24T15:39:34.960Z cpu3:3543984)VMotionRecv: 2961: 3117907752192811422 D: DONE paging in
2019-09-24T15:39:34.960Z cpu3:3543984)VMotionRecv: 2969: 3117907752192811422 D: Estimated network bandwidth 200.096 MB/s during page-in
2019-09-24T15:39:35.059Z cpu6:3543972)VMotion: 6675: 3117907752192811422 D: Received all changed pages.
2019-09-24T15:39:35.067Z cpu1:3543972)VMotion: 6454: 3117907752192811422 D: Resume handshake successful
2019-09-24T15:39:35.082Z cpu6:3543980)XVMotion: 642: Bitmap page: len = 16384, pgLen = 1, bitSet = 3001, bitClear = 13383.
2019-09-24T15:39:35.082Z cpu6:3543980)XVMotion: 642: Bitmap block: len = 131072, pgLen = 4, bitSet = 131072, bitClear = 0.

В выводе вы можете увидеть такие интересные вещи, как, например, средняя скорость (average bandwidth), которая была получена при передаче данных (см. вывод).

В папке с виртуальной машиной находится файл vmware.log, в котором также можно найти информацию о неудавшемся vMotion с учетом исходного и целевого IP-адресов хостов ESXi:

2019-09-24T15:38:47.280Z| vmx| I125: Received migrate ‘from’ request for mid id 3117907752192811422, src ip .
2019-09-24T15:38:47.280Z| vmx| I125: MigrateSetInfo: state=8 srcIp= dstIp= mid=3117907752192811422 uuid=4c4c4544-004a-4c10-8044-c7c04f4d4e32 priority=high
2019-09-24T15:38:47.282Z| vmx| I125: MigID: 3117907752192811422
2019-09-24T15:39:34.971Z| vmx| I125: Migrate_Open: Restoring from  with migration id 3117907752192811422
2019-09-24T15:39:35.023Z| vmx| I125: Migrate_Open: Restoring from  with migration id 3117907752192811422

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.