- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
Similar issue here. Upgraded one host in a cluster from 5.1U1 to 5.5U3. Cannot VMotion a subset of VMs from 5.1 hosts to the recently upgraded 5.5U3b host with the "Already Disconnected" errors at the 14% mark. The network settings are unchanged from before the upgrade and MTU is set at default 1500.
On a trial set of 10 VMs, 7 were able to VMotion over but 3 would not (the same 3 will continuously fail on multiple attempts).. If I power off the VM and start it back up, it is then able to VMotion around. However, this is not desirable solution for all the affected VMs across clusters.
Log snippets below from the source and destination hosts as well as VMX log.
SOURCE HOST vmkernel:
2016-01-19T17:28:12.164Z cpu0:9209)Config: 347: "SIOControlFlag2" = 1, Old Value: 0, (Status: 0x0)
2016-01-19T17:28:13.001Z cpu16:707103)Migrate: vm 707104: 3273: Setting VMOTION info: Source ts = 1453224491277421, src ip = <10.50.60.47> dest ip = <10.50.60.40> Dest wid = 1542062 using SHARED swap
2016-01-19T17:28:13.005Z cpu16:707103)Tcpip_Vmk: 1213: Affinitizing 10.55.66.47 to world 725253, Success
2016-01-19T17:28:13.005Z cpu16:707103)VMotion: 2688: 1453224491277421 S: Set ip address '10.55.66.47' worldlet affinity to send World ID 725253
2016-01-19T17:28:13.005Z cpu16:707103)Hbr: 3308: Migration start received (worldID=707104) (migrateType=1) (event=0) (isSource=1) (sharedConfig=1)
2016-01-19T17:28:13.005Z cpu22:8816)MigrateNet: vm 8816: 2077: Accepted connection from <10.55.66.40>
2016-01-19T17:28:13.005Z cpu22:8816)MigrateNet: vm 8816: 2147: dataSocket 0x4100172f77d0 receive buffer size is 563272
2016-01-19T17:28:13.005Z cpu29:725253)VMotionUtil: 3184: 1453224491277421 S: Stream connection 1 added.
2016-01-19T17:28:13.005Z cpu29:725253)VMotionUtil: 3184: 1453224491277421 S: Stream connection 2 added.
2016-01-19T17:28:13.010Z cpu6:725252)WARNING: VMotionUtil: 4526: 1453224491277421 S: socket connected returned: Already disconnected
2016-01-19T17:28:13.010Z cpu6:725252)WARNING: VMotionUtil: 6990: 1453224491277421 S: failed to flush stream buffer: Already disconnected
2016-01-19T17:28:13.010Z cpu6:725252)WARNING: VMotionUtil: 1617: 1453224491277421 S: failed writing stream completion: Already disconnected
2016-01-19T17:28:13.010Z cpu6:725252)WARNING: Migrate: 269: 1453224491277421 S: Failed: Already disconnected (0xbad002e) @0x0
2016-01-19T17:28:13.011Z cpu14:725251)WARNING: VMotionUtil: 4526: 1453224491277421 S: socket connected returned: Already disconnected
2016-01-19T17:28:13.011Z cpu14:725251)WARNING: VMotionUtil: 6990: 1453224491277421 S: failed to flush stream buffer: Already disconnected
2016-01-19T17:28:13.011Z cpu14:725251)WARNING: VMotionUtil: 1617: 1453224491277421 S: failed writing stream completion: Already disconnected
2016-01-19T17:28:13.048Z cpu20:707277)WARNING: Migrate: 5244: 1453224491277421 S: Migration considered a failure by the VMX. It is most likely a timeout, but check the VMX log for the true error.
2016-01-19T17:28:13.048Z cpu20:707277)Hbr: 3405: Migration end received (worldID=707104) (migrateType=1) (event=1) (isSource=1) (sharedConfig=1)
2016-01-19T17:28:13.119Z cpu9:10858)Config: 347: "SIOControlFlag2" = 0, Old Value: 1, (Status: 0x0)
DESTINATION HOST vmkernel:
2016-01-19T17:28:11.900Z cpu0:1537840 opID=6a039df0)World: 14369: VC opID C1B95B14-00000717-8c-e8-88 maps to vmkernel opID 6a039df0
2016-01-19T17:28:11.900Z cpu0:1537840 opID=6a039df0)Config: 346: "SIOControlFlag2" = 1, Old Value: 0, (Status: 0x0)
2016-01-19T17:28:11.918Z cpu27:1542061)MemSched: vm 1542061: 8311: extended swap to 8192 pgs
2016-01-19T17:28:12.139Z cpu27:1542061)World: vm 1542062: 1466: Starting world vmm0:linpsvcso04 of type 8
2016-01-19T17:28:12.139Z cpu27:1542061)Sched: vm 1542062: 6425: Adding world 'vmm0:linpsvcso04', group 'host/user', cpu: shares=-3 min=0 minLimit=-1 max=-1, mem: shares=-3 min=0 minLimit=-1 max=-1
2016-01-19T17:28:12.139Z cpu27:1542061)Sched: vm 1542062: 6440: renamed group 2944323 to vm.1542061
2016-01-19T17:28:12.139Z cpu27:1542061)Sched: vm 1542062: 6457: group 2944323 is located under group 4
2016-01-19T17:28:12.140Z cpu27:1542061)MemSched: vm 1542061: 8311: extended swap to 28148 pgs
2016-01-19T17:28:12.145Z cpu27:1542061)World: vm 1542064: 1466: Starting world vmm1:linpsvcso04 of type 8
2016-01-19T17:28:12.233Z cpu20:1542061)Migrate: vm 1542062: 3286: Setting VMOTION info: Dest ts = 1453224491277421, src ip = <10.55.66.47> dest ip = <10.55.66.40> Dest wid = 0 using SHARED swap
2016-01-19T17:28:12.235Z cpu5:1542066)CpuSched: 583: user latency of 1542066 vmotionStreamHelper0-1542062 0 changed by 1542066 vmotionStreamHelper0-1542062 -1
2016-01-19T17:28:12.236Z cpu28:1542067)CpuSched: 583: user latency of 1542067 vmotionStreamHelper1-1542062 0 changed by 1542067 vmotionStreamHelper1-1542062 -1
2016-01-19T17:28:12.236Z cpu18:1542069)CpuSched: 583: user latency of 1542069 vmotionRecvHelper-1542062 0 changed by 1542069 vmotionRecvHelper-1542062 -1
2016-01-19T17:28:12.237Z cpu16:1542068)CpuSched: 583: user latency of 1542068 vmotionSendHelper-1542062 0 changed by 1542068 vmotionSendHelper-1542062 -1
2016-01-19T17:28:12.237Z cpu20:1542061)Tcpip_Vmk: 1288: Affinitizing 10.55.66.40 to world 1542069, Success
2016-01-19T17:28:12.237Z cpu20:1542061)VMotion: 2735: 1453224491277421
Set ip address '10.55.66.40' worldlet affinity to recv World ID 1542069
2016-01-19T17:28:12.237Z cpu20:1542061)Hbr: 3340: Migration start received (worldID=1542062) (migrateType=1) (event=0) (isSource=0) (sharedConfig=1)
2016-01-19T17:28:12.364Z cpu4:33664)MigrateNet: vm 33664: 2096: Accepted connection from <10.55.66.47>
2016-01-19T17:28:12.364Z cpu4:33664)MigrateNet: vm 33664: 2138: data socket size 0 is less than config option 562140
2016-01-19T17:28:12.364Z cpu4:33664)MigrateNet: vm 33664: 2166: dataSocket 0x410b68c14300 receive buffer size is 562140
2016-01-19T17:28:12.365Z cpu4:33664)MigrateNet: vm 33664: 2096: Accepted connection from <10.55.66.47>
2016-01-19T17:28:12.365Z cpu4:33664)MigrateNet: vm 33664: 2138: data socket size 0 is less than config option 562140
2016-01-19T17:28:12.365Z cpu4:33664)MigrateNet: vm 33664: 2166: dataSocket 0x410b68c150e0 receive buffer size is 562140
2016-01-19T17:28:12.365Z cpu4:33664)VMotionUtil: 3396: 1453224491277421
Stream connection 1 added.
2016-01-19T17:28:12.365Z cpu4:33664)MigrateNet: vm 33664: 2096: Accepted connection from <10.55.66.47>
2016-01-19T17:28:12.365Z cpu4:33664)MigrateNet: vm 33664: 2138: data socket size 0 is less than config option 562140
2016-01-19T17:28:12.365Z cpu4:33664)MigrateNet: vm 33664: 2166: dataSocket 0x410b68edd700 receive buffer size is 562140
2016-01-19T17:28:12.365Z cpu4:33664)VMotionUtil: 3396: 1453224491277421
Stream connection 2 added.
2016-01-19T17:28:12.367Z cpu28:1542067)WARNING: Swap: 787: The migration swap type is not supported for migration.
2016-01-19T17:28:12.367Z cpu28:1542067)WARNING: VmMemMigrate: 1976: Received invalid swap slot data (0xc002d177) for pgNum 0x0.
2016-01-19T17:28:12.367Z cpu28:1542067)WARNING: VMotionRecv: 1116: 1453224491277421
failed to add memory page 0x0 to VM: Bad parameter
2016-01-19T17:28:12.367Z cpu28:1542067)WARNING: VMotionUtil: 1476: 1453224491277421
failed draining stream completion: Bad parameter
2016-01-19T17:28:12.367Z cpu28:1542067)WARNING: Migrate: 269: 1453224491277421
Failed: Bad parameter (0xbad0007) @0x418033856f9a
2016-01-19T17:28:12.370Z cpu0:1542066)WARNING: Swap: 787: The migration swap type is not supported for migration.
2016-01-19T17:28:12.370Z cpu0:1542066)WARNING: VmMemMigrate: 1976: Received invalid swap slot data (0xc0017c20) for pgNum 0x481.
2016-01-19T17:28:12.370Z cpu0:1542066)WARNING: VMotionRecv: 1116: 1453224491277421
failed to add memory page 0x481 to VM: Bad parameter
2016-01-19T17:28:12.370Z cpu0:1542066)WARNING: VMotionUtil: 1476: 1453224491277421
failed draining stream completion: Bad parameter
2016-01-19T17:28:12.370Z cpu0:1542066)VMotionUtil: 5333: 1453224491277421
Socket 0x410b68edd700 streamSock pending: 33304/33304 snd 561912 rcv
2016-01-19T17:28:12.370Z cpu0:1542066)VMotionUtil: 5333: 1453224491277421
Socket 0x410b68c150e0 streamSock pending: 33304/33304 snd 162585 rcv
2016-01-19T17:28:12.378Z cpu20:1542061)WARNING: Migrate: 5291: 1453224491277421
Migration considered a failure by the VMX. It is most likely a timeout, but check the VMX log for the true error.
2016-01-19T17:28:12.378Z cpu20:1542061)Hbr: 3434: Migration end received (worldID=1542062) (migrateType=1) (event=1) (isSource=0) (sharedConfig=1)
2016-01-19T17:28:12.413Z cpu17:1535207)Config: 346: "SIOControlFlag2" = 0, Old Value: 1, (Status: 0x0)
VMX_LOG:
2016-01-19T17:28:12.166Z| vmx| I120: VMXVmdbCbVmVmxMigrate: Got SET callback for /vm/#_VMX/vmx/migrateState/cmd/##1_22476/op/=to
2016-01-19T17:28:12.166Z| vmx| I120: Could not identify IP address family of in/srcLogIp:
2016-01-19T17:28:12.166Z| vmx| I120: Could not identify IP address family of in/dstLogIp:
2016-01-19T17:28:12.166Z| vmx| I120: VMXVmdbVmVmxMigrateGetParam: type: 1 srcIp=<10.55.66.47> dstIp=<10.55.66.40> mid=529b33194dc6d uuid=30303536-3734-5355-4533-34364c364c54 priority=high checksumMemory=no maxDowntime=0 encrypted=0 resumeDuringPageIn=no latencyAware=yes diskOpFile=
2016-01-19T17:28:12.166Z| vmx| I120: VMXVmdbVmVmxMigrateGetParam: type 1 unsharedSwap 0 memMinToTransfer 0 cpuMinToTransfer 0 numDisks 0 numStreamIps 1
2016-01-19T17:28:12.166Z| vmx| I120: Received migrate 'to' request for mid id 1453224491277421, src ip <10.55.66.47>, dst ip <10.55.66.40>(invalidate source config).
2016-01-19T17:28:12.167Z| vmx| I120: SVGA: Maximum display topology 2560x1600.
2016-01-19T17:28:12.184Z| vmx| I120: MigrateSetInfo: state=1 srcIp=<10.55.66.47> dstIp=<10.55.66.40> mid=1453224491277421 uuid=30303536-3734-5355-4533-34364c364c54 priority=high
2016-01-19T17:28:12.184Z| vmx| I120: MigrateSetState: Transitioning from state 0 to 1.
2016-01-19T17:28:12.184Z| vmx| I120: VMXVmdb_SetMigrationHostLogState: hostlog state transits to emigrating for migrate 'to' mid 1453224491277421
2016-01-19T17:28:12.902Z| vmx| I120: VMXVmdbCbVmVmxMigrate: Got SET callback for /vm/#_VMX/vmx/migrateState/cmd/##1_22479/op/=start
2016-01-19T17:28:12.902Z| vmx| I120: VMXVmdbVmVmxMigrateGetStartParam: mid=529b33194dc6d dstwid=1542062
2016-01-19T17:28:12.902Z| vmx| I120: Received migrate 'start' request for mig id 1453224491277421, dest world id 1542062.
2016-01-19T17:28:13.001Z| vmx| I120: SVGA: Maximum display topology 2560x1600.
2016-01-19T17:28:13.001Z| vmx| I120: MigratePlatformInitMigration: DiskOp file set to /vmfs/volumes/976d8169-6e977849/linpsvcso04/linpsvcso04-diskOp.tmp
2016-01-19T17:28:13.005Z| vmx| I120: MigrateSetState: Transitioning from state 1 to 2.
2016-01-19T17:28:13.011Z| vcpu-0| I120: VMXVmdb_SetMigrationHostLogState: hostlog state transits to failure for migrate 'to' mid 1453224491277421
2016-01-19T17:28:13.015Z| vcpu-0| I120: MigrateSetStateFinished: type=1 new state=5
2016-01-19T17:28:13.015Z| vcpu-0| I120: MigrateSetState: Transitioning from state 2 to 5.
2016-01-19T17:28:13.015Z| vcpu-0| I120: Migrate_SetFailureMsgList: switching to new log file.
2016-01-19T17:28:13.017Z| vcpu-0| I120: Migrate_SetFailureMsgList: Now in new log file.
2016-01-19T17:28:13.047Z| vcpu-0| I120: [msg.checkpoint.precopyfailure] Migration to host <10.55.66.40> failed with error Already disconnected (0xbad002e).
2016-01-19T17:28:13.048Z| vcpu-0| I120: Migrate: cleaning up migration state.
2016-01-19T17:28:13.048Z| vcpu-0| I120: MigrateSetState: Transitioning from state 5 to 0.
2016-01-19T17:28:13.048Z| vcpu-0| I120: Msg_Post: Error
2016-01-19T17:28:13.048Z| vcpu-0| I120: [vob.vmotion.transmit.vbuf.not.connected] vMotion migration [a010a2f:1453224491277421] socket connected returned: Already disconnected
2016-01-19T17:28:13.048Z| vcpu-0| I120: [vob.vmotion.stream.channel.write.no.wait.flush.failed] vMotion migration [a010a2f:1453224491277421] failed to flush stream buffer: Already disconnected
2016-01-19T17:28:13.049Z| vcpu-0| I120: [vob.vmotion.stream.completion.write.fail] vMotion migration [a010a2f:1453224491277421] failed writing stream completion: Already disconnected
2016-01-19T17:28:13.049Z| vcpu-0| I120: [msg.checkpoint.precopyfailure] Migration to host <10.55.66.40> failed with error Already disconnected (0xbad002e).
2016-01-19T17:28:13.049Z| vcpu-0| I120: ----------------------------------------