[번역] Troubleshooting vMotion
출처 : https://blogs.vmware.com/vsphere/2019/09/troubleshooting-vmotion.html
이전 블로그 게시물에서는 vMotion 프로세스(The vMotion Process Under the Hood)와 높은 대역폭 네트워크를 활용하여 실시간 마이그레이션 시간을 단축하는 방법을 살펴보았다. 이 글은 실시간 마이그레이션이 성공하지 못할 경우 vMotion 문제를 해결할 때 수행할 작업에 대한 자세한 정보를 얻기 위해 작성되었다. 마이그레이션이 실패한 대표적인 이유는 무엇인가? 조사해야 할 로그는? 문제를 해결하고 vMotion 작업이 실패하는 것을 방지하는 방법을 살펴봅겠다.
공통 장애
실시간 이동이 실패하는 일반적인 실패와 패턴은 다음과 같다.
- vMotion 네트워크 연결 문제
- ESXi 호스트는 20초 후에 ping 또는 시간 초과가 발생할 수 없음
- VMkernel 인터페이스와 네트워크 계층(예: 스위치 및 라우터) 간의 MTU 불일치
- ESXi 호스트에서 vMotion을 사용하도록 설정된 네트워크의 구성 잘못
- 스토리지
- 데이터스토어에 연결할 수 없거나, APD가 발생함(모든 경로 다운)
- I/O의 시간 초과 20초 이상
- vMotion에 성공했지만 게스트 문제가 발생함
- VM 네트워크에 연결할 수 없음 - 대상 ESXi 호스트에 L2 연결 없음
- 리소스가 오버 커밋됨
- 메모리를 오랫동안 할당할 수 없음
- 스와핑이 오래 걸려서 vMotion 시간 초과로 이어짐
모든 vMotion 요구 사항을 충족했는지 확인한다. 여기에는 네트워크 연결 또는 MTU 불일치의 vMotion 문제의 주요 이유가 포함된다. 이 문제를 정확히 파악할 수 없는 경우 vSphere 로그를 검토해서 어떤 일이 발생했는지 확인하는 것이 유용할 수 있다.
vSphere 로그
vSphere 로그를 자세히 들여다보면 실시간 마이그레이션이 실패하는 원인이 무엇인지 확인하는 데 유용하다. vMotion 프로세스는 vCenter Server 및 ESXi 구성 요소를 모두 사용한다. 다섯 가지 다른 로그 파일에 로그하는 다섯 가지 프로세스가 있다.
vCenter Daemon(VPXD), vCenter Agent(VPXA) 및 Host Daemon(hostd)은 vMotion 프로세스의 제어 영역이다. '데이터 평면'은 VMX 프로세스 및 VMkernel에 있다. 첫 번째 단계는 이러한 로그에서 Operation ID(opID)를 찾는 것이다. 이 opID는 Migration ID에 매핑된다. 이 두 개의 식별자를 사용해서, 해당 로그 파일을 확인해서 vMotion 프로세스 따라갈 수 있다.
Operation ID
vCenter Server 인스턴스의 VPXD 로그에서 vMotion 프로세스의 "작업 ID"를 찾으십시오. VCSA(vCenter Server Appliance) 인스턴스의 콘솔에 연결하고 바시 쉘로 이동하십시오. 다음 명령을 실행할 수 있음:
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
이제 Operation ID(opID)를 검색했다. 이것을 사용해서 ESXi 호스트의 hostd 로그 파일에서 opID를 이용해서 Migration ID를 찾는다. 관련된 소스 및 대상 ESXi 호스트를 알고 있을 때 유용하다. 이 예는 이전 명령을 사용해서 찾은 Operation ID를 사용하는 컴퓨팅 및 스토리지 vMotion(XvMotion) 이다.
grep jzlgfw8g-11824-auto-94h-h5:70003561-20 /var/log/hostd.log | grep -i migrate
Source ESXi host output:
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
Destination ESXi host output:
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 항목
이제 Migration ID를 확보했으므로, 이것을 사용해서 vmkernel 로그 파일에서 특정 실시간 마이그레이션에 대한 vMotion 프로세스의 정보를 추출할 수 있다. 소스 및 대상 ESXi 호스트에서 다음 명령을 사용한다.
grep VMotion /var/log/vmkernel*
출력은 vMotion 프로세스에서 데이터 전송에 사용되는 평균 대역폭과 같은 몇 가지 흥미로운 데이터 포인트를 보여준다.
Source ESXi host output:
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.
Destination ESXi host output:
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.
가상 시스템 로그 파일 항목
가상 시스템 로그 파일은 vmx 파일과 vmdk 파일도 포함하고 있는 가상 시스템의 홈 폴더에 있다. ESXi 호스트에서 root로 액세스 사용하면 적절한 폴더로 이동할 수 있다. 테스트 VM이 vSAN에 있으므로 symlink /vmfs/volumes/vsanDatastore를 사용해서 가상 시스템 홈 디렉토리를 찾는다. 다음 명령을 사용하면 소스 및 대상 IP 주소와 같은 실시간 마이그레이션에 대한 자세한 정보를 볼 수 있다.
grep "3117907752192811422" vmware.log
Output:
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 작업이 성공적이었음에도, 어떤 로그 항목이 사용되는지 보여주기 위한 것이다. 표시된 로그 항목에는 프로세스를 수행하는 데 도움이 되는 많은 상세 정보가 포함되어 있다. 만약 무언가가 실패한다면, 이 로그들은 가능한 원인을 찾기 위한 좋은 자원이 될 것이다.
추가 자료
- VMworld 2019 session ‘How to get the most out of vMotion’ : VMworld 계정 필요. <- 무료로 만들 수 있음. 강추!
- How to Tune vMotion for Lower Migration Times? : 번역본 있음 ^^
- The vMotion Process Under the Hood : 번역본 있음 ^^
- Enhanced vMotion Compatibility (EVC) Explained : 번역본 있음 ^^
- Long Distance vMotion : 내용이 안나옴 ㅠ.ㅠ
구강사의 간단 요약
- VCAP-DCV 시험에 vMotion 문제가 나온다 <- 그 만큼 많이 사용하고, 많은 상황이 발생한다는 것
- 1)네트워크 구성, 2)스토리지, 3)리소스 할당 등의 원인으로 문제가 발생할 수 있음
- 5개의 로그 파일을 본다 : 추가로 해당 VM 디렉토리에 있는 vmware.log 도 본다.
- Operation ID(opID)를 찾고 -> opID로 Migration ID 를 찾고 -> Migration ID로 VMkernel에서 관련 항목을 찾고 -> MigrationID로 VM의 vmware.log에서 찾는다
No Comments