Это перевод статьи Niels Hagoort Troubleshooting vMotion. Публикуется с разрешения автора.

В предыдущих статьях мы рассмотрели vMotion процесс (vMotion под капотом) и варианты использования сетей с высокой пропускной способностью для сокращения времени живой миграции (Как оптимизировать vMotion для сокращения времени миграции?). Эта статья посвящена отладке процесса живой миграции, что делать для устранении неполадок vMotion, что делать если динамическая миграция не работает. Каковы же типичные причины неудачных миграций? Какие логи посмотреть? Давайте разберем, как вы можете устранять неполадки и предотвращать сбои операций vMotion.

Типичные причины неудачных миграций

Проблемы в сети vMotion:

  • ESXi хосты не могут пинговать друг друга или таймаут превышает 20 секунд.
  • Несоответствие MTU между интерфейсом VMkernel и сетевым уровнем (т.е. коммутаторами и маршрутизаторами).
  • Неправильная настройка сетей VMotion на ESXi хостах.

Сторадж:

  • Хранилище недоступно или произошел ADP (All Paths Down).
  • Таймаут ввода-вывода 20 секунд или более.

vMotion прошел успешно, но есть проблемы с гостевыми ОС:

  • Сеть ВМ недоступна — нет соединения на 2 уровне у целевого ESXi хоста.

Переподписка ресурсов:

  • Не может быть выделена память.
  • Происходит своппинг, блокирующий vMotion.

Убедитесь, что вы выполнили все требования для vMotion. В том числе, основную причину проблем с vMotion, связанную с сетевым подключением или несоответствиями MTU. Если вы не можете точно определить проблему, будет полезно заглянуть в логи vSphere, чтобы разобраться, что же произошло.

Логи vSphere

vCenter Daemon (VPXD), vCenter Agent (VPXA) и Host Daemon (hostd) являются уровнем управления (Control Plane) для vMotion процесса. “Data Plane” — процессы VMX и VMkernel. Первый шаг — найти идентификатор операции (opID) в этих логах. Этот opID соответствует идентификатору миграции (Migration ID). Используя эти два идентификатора, мы можем следить за процессом vMotion, просматривая соответствующие логи.

Operation ID

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

Вывод этой команды поможет найти “Operation ID”:

/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)

Migration ID

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.LOCAL\Administrator] 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.LOCAL\Administrator] 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.LOCAL\Administrator] VMotionEntry: migrateType = 1

Логи VMkernel

grep VMotion /var/log/vmkernel*

Вывод команды показывает нам интересные данные о процессе vMotion, такие как средняя пропускная способность, используемая для передачи данных.

Вывод с исходного ESXi хоста:

2019-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 хоста:

019-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.

Лог виртуальной машины

grep "3117907752192811422" vmware.log

Вывод:

2019-09-24T15:38:47.280Z| vmx| I125: Received migrate ‘from’ request for mid id 3117907752192811422, src ip <192.168.200.93>.
2019-09-24T15:38:47.280Z| vmx| I125: MigrateSetInfo: state=8 srcIp=<192.168.200.93> dstIp=<192.168.200.91> 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 <192.168.200.93> with migration id 3117907752192811422
2019-09-24T15:39:35.023Z| vmx| I125: Migrate_Open: Restoring from <192.168.200.93> with migration id 3117907752192811422

Эта статья рассказывает, какие логи используются, если даже операция vMotion прошла успешно. Показанные логи содержат много подробной информации, которая поможет вам лучше понять процесс vMotion. Если что-то пошло не так, эти логи станут хорошим инструментом для поиска возможной причины.

Все, что здесь публикуется является моим персональным мнением. Не является мнением или позицией моих прошлых, текущих или будущих работодателей.

Все, что здесь публикуется является моим персональным мнением. Не является мнением или позицией моих прошлых, текущих или будущих работодателей.