VMware Cloud Community
MikeF0209
Contributor
Contributor

Virtual machine network disconnect during vMotion cutover

Hello,

I'm encountering a problem where VMs are loosing network connectivity right before cutover to new host when performing VMotion. 

My infrastructure is on HP Blades Gen 8  running Virtual Connect 3.70 connected to Nexus 5000 switches.  ESXi 5.1 Update 2 with VDs for the cluster.  VMotion is being performed on its own VLAN to segregate the traffic.  It was also happening on 5.1 Update 1.  I'm at a loss here.  Has anyone seen this before?

Migration of the VM completes but bot before some network timeouts.  I was made aware of the situation and watched a ping on the server while it was being migrated and it happens with all my VMs on any of the 5 clusters I have.

Any ideas?

Mike Fernandez Sr. Systems Engineer VCP-DCV5, MCSE 2008, MCSA 2012
Reply
0 Kudos
9 Replies
VirtuallyMikeB

I thought I knew what it was up to the time you said you were also experiencing this issue on hosts prior to 5.1 Update 2.  I just ran into this issue regarding e1000 virtual adapters.

http://kb.vmware.com/selfservice/microsites/search.do?language=en_US&cmd=displayKC&externalId=207269...

In the meantime, watch the logs while vMotioning to see what's going on.  Something like

~# tail -f /var/log/vmkernel.log

-----------------------------------------

Please consider marking this answer "correct" or "helpful" if you found it useful.

Mike Brown

VMware, Cisco Data Center, and NetApp dude

Consulting Engineer

michael.b.brown3@gmail.com

Twitter: @VirtuallyMikeB

Blog: http://VirtuallyMikeBrown.com

LinkedIn: http://LinkedIn.com/in/michaelbbrown

----------------------------------------- Please consider marking this answer "correct" or "helpful" if you found it useful (you'll get points too). Mike Brown VMware, Cisco Data Center, and NetApp dude Sr. Systems Engineer michael.b.brown3@gmail.com Twitter: @VirtuallyMikeB Blog: http://VirtuallyMikeBrown.com LinkedIn: http://LinkedIn.com/in/michaelbbrown
Reply
0 Kudos
MikeF0209
Contributor
Contributor

Thanks for the reply.  Checked your link but I don't think its that.  Here is the tail of the LOG

2014-04-22T11:42:04.172Z cpu0:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:42:04.173Z cpu0:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:43:18.927Z cpu26:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:43:18.927Z cpu26:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:44:22.375Z cpu0:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:44:22.375Z cpu0:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:45:23.933Z cpu1:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:45:23.933Z cpu1:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:46:22.393Z cpu23:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:46:22.394Z cpu23:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:47:28.936Z cpu7:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:47:28.936Z cpu7:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:48:22.395Z cpu6:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:48:22.395Z cpu6:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:49:33.463Z cpu18:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:49:33.463Z cpu18:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:50:48.448Z cpu18:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:50:48.449Z cpu18:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:51:42.378Z cpu16:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:51:42.378Z cpu16:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:52:53.422Z cpu18:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:52:53.422Z cpu18:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:54:08.369Z cpu18:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:54:08.370Z cpu18:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:55:23.948Z cpu22:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:55:23.948Z cpu22:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:56:22.448Z cpu0:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:56:22.449Z cpu0:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:57:28.954Z cpu19:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:57:28.954Z cpu19:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:58:22.459Z cpu7:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:58:22.460Z cpu7:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:58:52.055Z cpu26:10485)Config: 347: "SIOControlFlag2" = 1, Old Value: 0, (Status: 0x0)

2014-04-22T11:58:52.338Z cpu20:9195)Config: 347: "SIOControlFlag2" = 2, Old Value: 1, (Status: 0x0)

2014-04-22T11:58:52.454Z cpu28:10483)Config: 347: "SIOControlFlag2" = 3, Old Value: 2, (Status: 0x0)

2014-04-22T11:58:52.506Z cpu4:9199)Config: 347: "SIOControlFlag2" = 4, Old Value: 3, (Status: 0x0)

2014-04-22T11:58:53.358Z cpu24:6112664)Migrate: vm 6112665: 3273: Setting VMOTION info: Source ts = 1398167994401523, src ip = <172.20.32.102> dest ip = <172.20.32.112> Dest wid = 1874926 using SHARED swap

2014-04-22T11:58:53.360Z cpu24:6112664)Tcpip_Vmk: 1213: Affinitizing 172.20.32.102 to world 7414555, Success

2014-04-22T11:58:53.360Z cpu24:6112664)VMotion: 2688: 1398167994401523 S: Set ip address '172.20.32.102' worldlet affinity to send World ID 7414555

2014-04-22T11:58:53.360Z cpu24:6112664)Hbr: 3308: Migration start received (worldID=6112665) (migrateType=1) (event=0) (isSource=1) (sharedConfig=1)

2014-04-22T11:58:53.367Z cpu24:8813)MigrateNet: vm 8813: 2061: Accepted connection from <::ffff:172.20.32.112>

2014-04-22T11:58:53.367Z cpu24:8813)MigrateNet: vm 8813: 2131: dataSocket 0x41003a140210 receive buffer size is 563272

2014-04-22T11:58:53.367Z cpu0:7414555)VMotionUtil: 3184: 1398167994401523 S: Stream connection 1 added.

2014-04-22T11:58:53.367Z cpu0:7414555)VMotionUtil: 3184: 1398167994401523 S: Stream connection 2 added.

2014-04-22T11:58:53.632Z cpu15:5615570)Migrate: vm 5615571: 3273: Setting VMOTION info: Source ts = 1398167994592542, src ip = <172.20.32.102> dest ip = <172.20.32.99> Dest wid = 78062 using SHARED swap

2014-04-22T11:58:53.635Z cpu15:5615570)Tcpip_Vmk: 1213: Affinitizing 172.20.32.102 to world 7226143, Success

2014-04-22T11:58:53.635Z cpu15:5615570)VMotion: 2688: 1398167994592542 S: Set ip address '172.20.32.102' worldlet affinity to send World ID 7226143

2014-04-22T11:58:53.635Z cpu15:5615570)Hbr: 3308: Migration start received (worldID=5615571) (migrateType=1) (event=0) (isSource=1) (sharedConfig=1)

2014-04-22T11:58:53.636Z cpu24:8813)MigrateNet: vm 8813: 2061: Accepted connection from <::ffff:172.20.32.99>

2014-04-22T11:58:53.636Z cpu24:8813)MigrateNet: vm 8813: 2131: dataSocket 0x410037cebd10 receive buffer size is 563272

2014-04-22T11:58:53.636Z cpu20:7226143)VMotionUtil: 3184: 1398167994592542 S: Stream connection 1 added.

2014-04-22T11:58:53.637Z cpu22:7226143)VMotionUtil: 3184: 1398167994592542 S: Stream connection 2 added.

2014-04-22T11:58:53.709Z cpu27:6074840)Migrate: vm 6074841: 3273: Setting VMOTION info: Source ts = 1398167994577540, src ip = <172.20.32.102> dest ip = <172.20.32.108> Dest wid = 7133804 using SHARED swap

2014-04-22T11:58:53.712Z cpu27:6074840)Tcpip_Vmk: 1213: Affinitizing 172.20.32.102 to world 7226147, Success

2014-04-22T11:58:53.712Z cpu27:6074840)VMotion: 2688: 1398167994577540 S: Set ip address '172.20.32.102' worldlet affinity to send World ID 7226147

2014-04-22T11:58:53.712Z cpu27:6074840)Hbr: 3308: Migration start received (worldID=6074841) (migrateType=1) (event=0) (isSource=1) (sharedConfig=1)

2014-04-22T11:58:53.713Z cpu24:8813)MigrateNet: vm 8813: 2061: Accepted connection from <::ffff:172.20.32.108>

2014-04-22T11:58:53.713Z cpu24:8813)MigrateNet: vm 8813: 2131: dataSocket 0x41003a440010 receive buffer size is 563272

2014-04-22T11:58:53.713Z cpu21:7226147)VMotionUtil: 3184: 1398167994577540 S: Stream connection 1 added.

2014-04-22T11:58:53.713Z cpu22:7226147)VMotionUtil: 3184: 1398167994577540 S: Stream connection 2 added.

2014-04-22T11:58:53.827Z cpu1:6549788)Migrate: vm 6549789: 3273: Setting VMOTION info: Source ts = 1398167994579540, src ip = <172.20.32.102> dest ip = <172.20.32.104> Dest wid = 7346346 using SHARED swap

2014-04-22T11:58:53.830Z cpu1:6549788)Tcpip_Vmk: 1213: Affinitizing 172.20.32.102 to world 7414567, Success

2014-04-22T11:58:53.830Z cpu1:6549788)VMotion: 2688: 1398167994579540 S: Set ip address '172.20.32.102' worldlet affinity to send World ID 7414567

2014-04-22T11:58:53.830Z cpu1:6549788)Hbr: 3308: Migration start received (worldID=6549789) (migrateType=1) (event=0) (isSource=1) (sharedConfig=1)

2014-04-22T11:58:53.831Z cpu24:8813)MigrateNet: vm 8813: 2061: Accepted connection from <::ffff:172.20.32.104>

2014-04-22T11:58:53.831Z cpu24:8813)MigrateNet: vm 8813: 2131: dataSocket 0x41002c4d2610 receive buffer size is 563272

2014-04-22T11:58:53.832Z cpu1:7414567)VMotionUtil: 3184: 1398167994579540 S: Stream connection 1 added.

2014-04-22T11:58:53.832Z cpu1:7414567)VMotionUtil: 3184: 1398167994579540 S: Stream connection 2 added.

2014-04-22T11:59:33.867Z cpu16:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:59:33.867Z cpu16:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T11:59:54.898Z cpu3:5615571)VMotion: 4417: 1398167994592542 S: Stopping pre-copy: only 20043 pages left to send, which can be sent within the switchover time goal of 0.500 seconds (network bandwidth ~58.087 MB/s, 124202% t2d)

2014-04-22T11:59:55.031Z cpu0:5615771)VSCSI: 6335: handle 8221(vscsi0:0):Destroying Device for world 5615571 (pendCom 0)

2014-04-22T11:59:55.065Z cpu0:5615771)NetPort: 1574: disabled port 0x400003e

2014-04-22T11:59:58.726Z cpu22:7226143)VMotionSend: 3640: 1398167994592542 S: Sent all modified pages to destination (network bandwidth ~52.892 MB/s)

2014-04-22T11:59:59.652Z cpu1:5615570)Hbr: 3405: Migration end received (worldID=5615571) (migrateType=1) (event=1) (isSource=1) (sharedConfig=1)

2014-04-22T11:59:59.657Z cpu30:8252)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T11:59:59.657Z cpu30:8252)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T11:59:59.657Z cpu30:8252)Net: 2470: dissociate dvPort 11 from port 0x400003e

2014-04-22T11:59:59.657Z cpu30:8252)Net: 2475: disconnected client from port 0x400003e

2014-04-22T12:00:00.816Z cpu24:10485)Config: 347: "SIOControlFlag2" = 3, Old Value: 4, (Status: 0x0)

2014-04-22T12:00:02.154Z cpu28:10486)Config: 347: "SIOControlFlag2" = 4, Old Value: 3, (Status: 0x0)

2014-04-22T12:00:07.256Z cpu5:7342409)Migrate: vm 7342410: 3273: Setting VMOTION info: Source ts = 1398167994578540, src ip = <172.20.32.102> dest ip = <172.20.32.111> Dest wid = 5953553 using SHARED swap

2014-04-22T12:00:07.259Z cpu5:7342409)Tcpip_Vmk: 1213: Affinitizing 172.20.32.102 to world 7414798, Success

2014-04-22T12:00:07.259Z cpu5:7342409)VMotion: 2688: 1398167994578540 S: Set ip address '172.20.32.102' worldlet affinity to send World ID 7414798

2014-04-22T12:00:07.259Z cpu5:7342409)Hbr: 3308: Migration start received (worldID=7342410) (migrateType=1) (event=0) (isSource=1) (sharedConfig=1)

2014-04-22T12:00:07.310Z cpu24:8813)MigrateNet: vm 8813: 2061: Accepted connection from <::ffff:172.20.32.111>

2014-04-22T12:00:07.310Z cpu24:8813)MigrateNet: vm 8813: 2131: dataSocket 0x410037d1d910 receive buffer size is 563272

2014-04-22T12:00:07.322Z cpu23:7414798)VMotionUtil: 3184: 1398167994578540 S: Stream connection 1 added.

2014-04-22T12:00:07.334Z cpu18:7414798)VMotionUtil: 3184: 1398167994578540 S: Stream connection 2 added.

2014-04-22T12:00:07.359Z cpu4:7414798)VMotion: 6333: 1398167994578540 S: Detected 11Ms round-trip latency to remote host.

2014-04-22T12:00:07.359Z cpu4:7414798)MigrateNet: 1483: 1398167994578540 S: Adjusted socket 0x410037d41910 send buffer to 1534060 based on 11448Us round-trip latency.

2014-04-22T12:00:07.359Z cpu4:7414798)MigrateNet: 1483: 1398167994578540 S: Adjusted socket 0x41003a47ce10 send buffer to 1534060 based on 11448Us round-trip latency.

2014-04-22T12:00:07.359Z cpu4:7414798)MigrateNet: 1483: 1398167994578540 S: Adjusted socket 0x41003a393010 send buffer to 1534060 based on 11448Us round-trip latency.

2014-04-22T12:00:42.378Z cpu16:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:00:42.378Z cpu16:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:01:33.890Z cpu1:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:01:33.890Z cpu1:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:02:25.868Z cpu8:7342410)VMotion: 4502: 1398167994578540 S: Another pre-copy iteration needed with 299984 pages left to send (prev2 6291456, prev 6291456, network bandwidth ~99.088 MB/s, 5126% t2d)

2014-04-22T12:02:28.727Z cpu4:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:02:28.728Z cpu4:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:02:33.509Z cpu18:6074841)VMotion: 4502: 1398167994577540 S: Another pre-copy iteration needed with 68550 pages left to send (prev2 6291456, prev 6291456, network bandwidth ~51.386 MB/s, 30749% t2d)

2014-04-22T12:02:33.858Z cpu10:7342410)VMotion: 4502: 1398167994578540 S: Another pre-copy iteration needed with 39706 pages left to send (prev2 6291456, prev 145, network bandwidth ~117.582 MB/s, 740% t2d)

2014-04-22T12:02:35.253Z cpu0:7342410)VMotion: 4502: 1398167994578540 S: Another pre-copy iteration needed with 15279 pages left to send (prev2 145, prev 151, network bandwidth ~117.093 MB/s, 214% t2d)

2014-04-22T12:02:35.853Z cpu12:7342410)VMotion: 4417: 1398167994578540 S: Stopping pre-copy: only 7379 pages left to send, which can be sent within the switchover time goal of 0.500 seconds (network bandwidth ~116.977 MB/s, 175% t2d)

2014-04-22T12:02:35.966Z cpu4:7342665)NetPort: 1574: disabled port 0x4000046

2014-04-22T12:02:35.966Z cpu4:7342665)NetPort: 1574: disabled port 0x5000036

2014-04-22T12:02:37.705Z cpu16:6074841)VMotion: 4417: 1398167994577540 S: Stopping pre-copy: only 3274 pages left to send, which can be sent within the switchover time goal of 0.500 seconds (network bandwidth ~56.248 MB/s, 2097% t2d)

2014-04-22T12:02:37.829Z cpu30:6075098)NetPort: 1574: disabled port 0x4000040

2014-04-22T12:02:37.829Z cpu30:6075098)NetPort: 1574: disabled port 0x5000030

2014-04-22T12:02:39.741Z cpu16:7414798)VMotionSend: 3640: 1398167994578540 S: Sent all modified pages to destination (network bandwidth ~21.041 MB/s)

2014-04-22T12:02:40.283Z cpu3:7342409)Hbr: 3405: Migration end received (worldID=7342410) (migrateType=1) (event=1) (isSource=1) (sharedConfig=1)

2014-04-22T12:02:40.288Z cpu16:8252)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:02:40.288Z cpu16:8252)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:02:40.288Z cpu16:8252)Net: 2470: dissociate dvPort à\4  from port 0x5000036

2014-04-22T12:02:40.288Z cpu16:8252)Net: 2475: disconnected client from port 0x5000036

2014-04-22T12:02:40.288Z cpu16:8252)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:02:40.288Z cpu16:8252)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:02:40.288Z cpu16:8252)Net: 2470: dissociate dvPort 418 from port 0x4000046

2014-04-22T12:02:40.288Z cpu16:8252)Net: 2475: disconnected client from port 0x4000046

2014-04-22T12:02:41.313Z cpu0:7226147)VMotionSend: 3640: 1398167994577540 S: Sent all modified pages to destination (network bandwidth ~39.617 MB/s)

2014-04-22T12:02:41.845Z cpu20:6074840)Hbr: 3405: Migration end received (worldID=6074841) (migrateType=1) (event=1) (isSource=1) (sharedConfig=1)

2014-04-22T12:02:41.852Z cpu31:8252)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:02:41.852Z cpu31:8252)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:02:41.852Z cpu31:8252)Net: 2470: dissociate dvPort 431 from port 0x5000030

2014-04-22T12:02:41.852Z cpu31:8252)Net: 2475: disconnected client from port 0x5000030

2014-04-22T12:02:41.852Z cpu31:8252)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:02:41.852Z cpu31:8252)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:02:41.852Z cpu31:8252)Net: 2470: dissociate dvPort Àª5  from port 0x4000040

2014-04-22T12:02:41.852Z cpu31:8252)Net: 2475: disconnected client from port 0x4000040

2014-04-22T12:02:42.184Z cpu26:5540469)Config: 347: "SIOControlFlag2" = 3, Old Value: 4, (Status: 0x0)

2014-04-22T12:02:43.546Z cpu18:10485)Config: 347: "SIOControlFlag2" = 2, Old Value: 3, (Status: 0x0)

2014-04-22T12:02:43.864Z cpu2:9179)Config: 347: "SIOControlFlag2" = 3, Old Value: 2, (Status: 0x0)

2014-04-22T12:02:45.221Z cpu18:10476)Config: 347: "SIOControlFlag2" = 4, Old Value: 3, (Status: 0x0)

2014-04-22T12:02:46.055Z cpu6:6843513)Migrate: vm 6843514: 3273: Setting VMOTION info: Source ts = 1398167994589541, src ip = <172.20.32.102> dest ip = <172.20.32.104> Dest wid = 7346724 using SHARED swap

2014-04-22T12:02:46.060Z cpu6:6843513)Tcpip_Vmk: 1213: Affinitizing 172.20.32.102 to world 7415034, Success

2014-04-22T12:02:46.060Z cpu6:6843513)VMotion: 2688: 1398167994589541 S: Set ip address '172.20.32.102' worldlet affinity to send World ID 7415034

2014-04-22T12:02:46.060Z cpu6:6843513)Hbr: 3308: Migration start received (worldID=6843514) (migrateType=1) (event=0) (isSource=1) (sharedConfig=1)

2014-04-22T12:02:46.085Z cpu24:8813)MigrateNet: vm 8813: 2061: Accepted connection from <::ffff:172.20.32.104>

2014-04-22T12:02:46.085Z cpu24:8813)MigrateNet: vm 8813: 2131: dataSocket 0x410037d21710 receive buffer size is 563272

2014-04-22T12:02:46.093Z cpu6:7415034)VMotionUtil: 3184: 1398167994589541 S: Stream connection 1 added.

2014-04-22T12:02:46.102Z cpu16:7415034)VMotionUtil: 3184: 1398167994589541 S: Stream connection 2 added.

2014-04-22T12:02:46.119Z cpu22:7415034)VMotion: 6333: 1398167994589541 S: Detected 8Ms round-trip latency to remote host.

2014-04-22T12:02:46.119Z cpu22:7415034)MigrateNet: 1483: 1398167994589541 S: Adjusted socket 0x41003a421810 send buffer to 1115680 based on 8452Us round-trip latency.

2014-04-22T12:02:46.119Z cpu22:7415034)MigrateNet: 1483: 1398167994589541 S: Adjusted socket 0x410037cebd10 send buffer to 1115680 based on 8452Us round-trip latency.

2014-04-22T12:02:46.119Z cpu22:7415034)MigrateNet: 1483: 1398167994589541 S: Adjusted socket 0x410037cd9510 send buffer to 1115680 based on 8452Us round-trip latency.

2014-04-22T12:02:47.036Z cpu16:7348328)Migrate: vm 7348329: 3273: Setting VMOTION info: Source ts = 1398167994578541, src ip = <172.20.32.102> dest ip = <172.20.32.107> Dest wid = 7344117 using SHARED swap

2014-04-22T12:02:47.040Z cpu16:7348328)Tcpip_Vmk: 1213: Affinitizing 172.20.32.102 to world 7415040, Success

2014-04-22T12:02:47.040Z cpu16:7348328)VMotion: 2688: 1398167994578541 S: Set ip address '172.20.32.102' worldlet affinity to send World ID 7415040

2014-04-22T12:02:47.040Z cpu16:7348328)Hbr: 3308: Migration start received (worldID=7348329) (migrateType=1) (event=0) (isSource=1) (sharedConfig=1)

2014-04-22T12:02:47.072Z cpu19:8813)MigrateNet: vm 8813: 2061: Accepted connection from <::ffff:172.20.32.107>

2014-04-22T12:02:47.072Z cpu19:8813)MigrateNet: vm 8813: 2131: dataSocket 0x41003a112810 receive buffer size is 563272

2014-04-22T12:02:47.083Z cpu9:7415040)VMotionUtil: 3184: 1398167994578541 S: Stream connection 1 added.

2014-04-22T12:02:47.094Z cpu4:7415040)VMotionUtil: 3184: 1398167994578541 S: Stream connection 2 added.

2014-04-22T12:02:47.119Z cpu2:7415040)VMotion: 6333: 1398167994578541 S: Detected 12Ms round-trip latency to remote host.

2014-04-22T12:02:47.119Z cpu2:7415040)MigrateNet: 1483: 1398167994578541 S: Adjusted socket 0x41003a384610 send buffer to 1673520 based on 12064Us round-trip latency.

2014-04-22T12:02:47.119Z cpu2:7415040)MigrateNet: 1483: 1398167994578541 S: Adjusted socket 0x41003a475a10 send buffer to 1673520 based on 12064Us round-trip latency.

2014-04-22T12:02:47.119Z cpu2:7415040)MigrateNet: 1483: 1398167994578541 S: Adjusted socket 0x4100378afd10 send buffer to 1673520 based on 12064Us round-trip latency.

2014-04-22T12:03:25.700Z cpu10:6549789)VMotion: 4502: 1398167994579540 S: Another pre-copy iteration needed with 925338 pages left to send (prev2 6291456, prev 6291456, network bandwidth ~52.757 MB/s, 2050% t2d)

2014-04-22T12:03:31.965Z cpu20:6112665)VMotion: 4502: 1398167994401523 S: Another pre-copy iteration needed with 688058 pages left to send (prev2 6291456, prev 6291456, network bandwidth ~54.626 MB/s, 1785% t2d)

2014-04-22T12:03:33.900Z cpu20:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:03:33.900Z cpu20:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:04:11.318Z cpu20:6112665)VMotion: 4502: 1398167994401523 S: Another pre-copy iteration needed with 155467 pages left to send (prev2 6291456, prev 171, network bandwidth ~44.772 MB/s, 408% t2d)

2014-04-22T12:04:12.367Z cpu5:6549789)VMotion: 4502: 1398167994579540 S: Another pre-copy iteration needed with 200786 pages left to send (prev2 6291456, prev 222, network bandwidth ~46.746 MB/s, 438% t2d)

2014-04-22T12:04:16.235Z cpu15:6843514)VMotion: 4417: 1398167994589541 S: Stopping pre-copy: only 34461 pages left to send, which can be sent within the switchover time goal of 0.500 seconds (network bandwidth ~71.467 MB/s, 43146% t2d)

2014-04-22T12:04:16.367Z cpu15:6810948)NetPort: 1574: disabled port 0x4000044

2014-04-22T12:04:16.368Z cpu15:6810948)NetPort: 1574: disabled port 0x5000034

2014-04-22T12:04:20.449Z cpu0:7415034)VMotionSend: 3640: 1398167994589541 S: Sent all modified pages to destination (network bandwidth ~61.829 MB/s)

2014-04-22T12:04:21.115Z cpu15:6843513)Hbr: 3405: Migration end received (worldID=6843514) (migrateType=1) (event=1) (isSource=1) (sharedConfig=1)

2014-04-22T12:04:21.122Z cpu10:8250)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:04:21.122Z cpu10:8250)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:04:21.122Z cpu10:8250)Net: 2470: dissociate dvPort о   from port 0x5000034

2014-04-22T12:04:21.122Z cpu10:8250)Net: 2475: disconnected client from port 0x5000034

2014-04-22T12:04:21.122Z cpu10:8250)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:04:21.122Z cpu10:8250)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:04:21.122Z cpu10:8250)Net: 2470: dissociate dvPort 124 from port 0x4000044

2014-04-22T12:04:21.122Z cpu10:8250)Net: 2475: disconnected client from port 0x4000044

2014-04-22T12:04:22.296Z cpu8:4109694)Config: 347: "SIOControlFlag2" = 3, Old Value: 4, (Status: 0x0)

2014-04-22T12:04:23.773Z cpu16:6112665)VMotion: 4502: 1398167994401523 S: Another pre-copy iteration needed with 76864 pages left to send (prev2 171, prev 189, network bandwidth ~52.543 MB/s, 177% t2d)

2014-04-22T12:04:30.535Z cpu16:6112665)VMotion: 4502: 1398167994401523 S: Another pre-copy iteration needed with 54562 pages left to send (prev2 189, prev 426, network bandwidth ~53.622 MB/s, 135% t2d)

2014-04-22T12:04:31.776Z cpu8:6549789)VMotion: 4443: 1398167994579540 S: Not enough forward progress, enabling SDPS (Pages left to send: prev2 222, prev 294, cur 270315, network bandwidth ~52.826 MB/s, 82% t2d)

2014-04-22T12:04:33.276Z cpu2:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:04:33.276Z cpu2:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:04:36.274Z cpu22:6112665)VMotion: 4443: 1398167994401523 S: Not enough forward progress, enabling SDPS (Pages left to send: prev2 426, prev 368, cur 63488, network bandwidth ~47.948 MB/s, 87% t2d)

2014-04-22T12:04:42.029Z cpu28:6112665)VMotion: 4502: 1398167994401523 S: Another pre-copy iteration needed with 10097 pages left to send (prev2 368, prev 155, network bandwidth ~45.347 MB/s, 464% t2d)

2014-04-22T12:04:43.027Z cpu24:6112665)VMotion: 4417: 1398167994401523 S: Stopping pre-copy: only 1383 pages left to send, which can be sent within the switchover time goal of 0.500 seconds (network bandwidth ~45.285 MB/s, 447% t2d)

2014-04-22T12:04:43.284Z cpu17:6112932)NetPort: 1574: disabled port 0x4000041

2014-04-22T12:04:43.284Z cpu17:6112932)NetPort: 1574: disabled port 0x5000031

2014-04-22T12:04:48.611Z cpu19:7414555)VMotionSend: 3640: 1398167994401523 S: Sent all modified pages to destination (network bandwidth ~5.844 MB/s)

2014-04-22T12:04:49.035Z cpu6:6549789)VMotion: 4502: 1398167994579540 S: Another pre-copy iteration needed with 43727 pages left to send (prev2 294, prev 188, network bandwidth ~48.941 MB/s, 500% t2d)

2014-04-22T12:04:49.716Z cpu22:6112664)Hbr: 3405: Migration end received (worldID=6112665) (migrateType=1) (event=1) (isSource=1) (sharedConfig=1)

2014-04-22T12:04:49.721Z cpu31:8251)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:04:49.721Z cpu31:8251)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:04:49.721Z cpu31:8251)Net: 2470: dissociate dvPort  ¾   from port 0x5000031

2014-04-22T12:04:49.721Z cpu31:8251)Net: 2475: disconnected client from port 0x5000031

2014-04-22T12:04:49.722Z cpu31:8251)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:04:49.722Z cpu31:8251)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:04:49.722Z cpu31:8251)Net: 2470: dissociate dvPort °°3  from port 0x4000041

2014-04-22T12:04:49.722Z cpu31:8251)Net: 2475: disconnected client from port 0x4000041

2014-04-22T12:04:51.651Z cpu8:10483)Config: 347: "SIOControlFlag2" = 2, Old Value: 3, (Status: 0x0)

2014-04-22T12:04:52.505Z cpu1:6549789)VMotion: 4417: 1398167994579540 S: Stopping pre-copy: only 4352 pages left to send, which can be sent within the switchover time goal of 0.500 seconds (network bandwidth ~55.926 MB/s, 502% t2d)

2014-04-22T12:04:52.701Z cpu1:6550012)NetPort: 1574: disabled port 0x4000043

2014-04-22T12:04:52.701Z cpu1:6550012)NetPort: 1574: disabled port 0x5000033

2014-04-22T12:04:56.820Z cpu3:7414567)VMotionSend: 3640: 1398167994579540 S: Sent all modified pages to destination (network bandwidth ~18.160 MB/s)

2014-04-22T12:04:57.363Z cpu8:6549788)Hbr: 3405: Migration end received (worldID=6549789) (migrateType=1) (event=1) (isSource=1) (sharedConfig=1)

2014-04-22T12:04:57.369Z cpu1:8251)WARNING: Uplink: 3622: requesting cap 0x0!

2014-04-22T12:04:57.369Z cpu1:8251)WARNING: Uplink: 3622: requesting cap 0x0!

2014-04-22T12:04:57.369Z cpu1:8251)Net: 2470: dissociate dvPort 82 from port 0x5000033

2014-04-22T12:04:57.369Z cpu1:8251)Net: 2475: disconnected client from port 0x5000033

2014-04-22T12:04:57.369Z cpu1:8251)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:04:57.369Z cpu1:8251)WARNING: Uplink: 3075: releasing cap 0x0!

2014-04-22T12:04:57.369Z cpu1:8251)Net: 2470: dissociate dvPort 445 from port 0x4000043

2014-04-22T12:04:57.369Z cpu1:8251)Net: 2475: disconnected client from port 0x4000043

2014-04-22T12:04:59.627Z cpu20:10412)Config: 347: "SIOControlFlag2" = 1, Old Value: 2, (Status: 0x0)

2014-04-22T12:05:48.486Z cpu21:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:05:48.486Z cpu21:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:07:03.970Z cpu1:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:07:03.970Z cpu1:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:08:02.987Z cpu3:7348329)VMotion: 4502: 1398167994578541 S: Another pre-copy iteration needed with 1673864 pages left to send (prev2 16777216, prev 16777216, network bandwidth ~177.812 MB/s, 7386% t2d)

2014-04-22T12:08:18.857Z cpu13:7348329)VMotion: 4502: 1398167994578541 S: Another pre-copy iteration needed with 290300 pages left to send (prev2 16777216, prev 178, network bandwidth ~238.725 MB/s, 464% t2d)

2014-04-22T12:08:18.972Z cpu16:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:08:18.972Z cpu16:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:08:23.975Z cpu11:7348329)VMotion: 4502: 1398167994578541 S: Another pre-copy iteration needed with 127681 pages left to send (prev2 178, prev 219, network bandwidth ~239.383 MB/s, 188% t2d)

2014-04-22T12:08:26.862Z cpu8:7348329)VMotion: 4502: 1398167994578541 S: Another pre-copy iteration needed with 69956 pages left to send (prev2 219, prev 171, network bandwidth ~240.096 MB/s, 147% t2d)

2014-04-22T12:08:28.582Z cpu0:7348329)VMotion: 4417: 1398167994578541 S: Stopping pre-copy: only 14214 pages left to send, which can be sent within the switchover time goal of 0.500 seconds (network bandwidth ~187.309 MB/s, 314% t2d)

2014-04-22T12:08:28.632Z cpu13:7349416)VSCSI: 6335: handle 8222(vscsi0:0):Destroying Device for world 7348329 (pendCom 0)

2014-04-22T12:08:28.633Z cpu13:7349416)VSCSI: 6335: handle 8223(vscsi0:1):Destroying Device for world 7348329 (pendCom 0)

2014-04-22T12:08:28.635Z cpu13:7349416)NetPort: 1574: disabled port 0x4000047

2014-04-22T12:08:29.277Z cpu9:7415040)VMotionSend: 3640: 1398167994578541 S: Sent all modified pages to destination (network bandwidth ~232.146 MB/s)

2014-04-22T12:08:30.381Z cpu2:7348328)Hbr: 3405: Migration end received (worldID=7348329) (migrateType=1) (event=1) (isSource=1) (sharedConfig=1)

2014-04-22T12:08:30.390Z cpu6:8250)WARNING: Uplink: 3622: requesting cap 0x0!

2014-04-22T12:08:30.390Z cpu6:8250)WARNING: Uplink: 3622: requesting cap 0x0!

2014-04-22T12:08:30.390Z cpu6:8250)Net: 2470: dissociate dvPort .!  from port 0x4000047

2014-04-22T12:08:30.390Z cpu6:8250)Net: 2475: disconnected client from port 0x4000047

2014-04-22T12:08:34.679Z cpu22:5540469)Config: 347: "SIOControlFlag2" = 0, Old Value: 1, (Status: 0x0)

2014-04-22T12:09:33.975Z cpu20:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:09:33.975Z cpu20:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:09:46.219Z cpu10:7416332)WARNING: UserTeletype: 1639: Unknown cmd 0x5409 (data 0x1) for slave

2014-04-22T12:10:38.692Z cpu26:8218)<4>hpsa 0000:03:00.0: Device:C0:B0:T0:L1 Command:0x85 CC:05/20/00 Illegal Request.

2014-04-22T12:10:38.692Z cpu10:8202)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x85 (0x412484cb2e80, 9400) to dev "naa.600508b1001c0937914f9ec60c0d5103" on path "vmhba0:C0:T0:L1" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE

2014-04-22T12:10:38.692Z cpu10:8202)ScsiDeviceIO: 2316: Cmd(0x412484cb2e80) 0x85, CmdSN 0x4d01 from world 9400 to dev "naa.600508b1001c0937914f9ec60c0d5103" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.

2014-04-22T12:10:38.694Z cpu26:8218)<4>hpsa 0000:03:00.0: Device:C0:B0:T0:L1 Command:0x85 CC:05/20/00 Illegal Request.

2014-04-22T12:10:38.694Z cpu10:8202)ScsiDeviceIO: 2316: Cmd(0x412484cb2e80) 0x85, CmdSN 0x4d02 from world 9400 to dev "naa.600508b1001c0937914f9ec60c0d5103" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.

2014-04-22T12:10:38.694Z cpu10:8202)ScsiDeviceIO: 2316: Cmd(0x412484cb2e80) 0x4d, CmdSN 0x4d03 from world 9400 to dev "naa.600508b1001c0937914f9ec60c0d5103" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.

2014-04-22T12:10:48.503Z cpu20:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:10:48.504Z cpu20:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:11:44.183Z cpu25:7416429)WARNING: UserLinux: 1331: unsupported: (void)

2014-04-22T12:12:03.981Z cpu20:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:12:03.982Z cpu20:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:13:18.984Z cpu20:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

2014-04-22T12:13:18.984Z cpu20:9595)etherswitch: ESVsiGetParamPortCfg:392: : not found

Mike Fernandez Sr. Systems Engineer VCP-DCV5, MCSE 2008, MCSA 2012
Reply
0 Kudos
GMCON
Enthusiast
Enthusiast

Since this is happening across all clusters and different vSphere version I would be looking at your switch configs honestly.  Make sure your physical switch ports for all your hosts are configured with portfast, if not this could always lead to some packet loss when the switch sees the mac on a different port all of a sudden.

MikeF0209
Contributor
Contributor

Thanks GMCON.  We are connected to Nexus switches which is a bit different. Edge ports on the nexus are set to "normal" by default.  I may have to put a call to Cisco and see what they recommend.

It is best practice for the ports to have portfast enabled?

Mike Fernandez Sr. Systems Engineer VCP-DCV5, MCSE 2008, MCSA 2012
Reply
0 Kudos
GMCON
Enthusiast
Enthusiast

I haven't worked much with the Nexus switches but yes VMware recommends Portfast on the uplink ports for hosts. It seems to be on the Nexus switches portfast equivalent is Port Edge It may not be the issue but it should get you looking to make sure your physical ports are configured properly across the environment and your vDS per recommendations.  That is just because it is happening across all clusters and multiple software versions.

MikeF0209
Contributor
Contributor

Thanks let's see what Cisco says and I'll post an update here.

Mike Fernandez Sr. Systems Engineer VCP-DCV5, MCSE 2008, MCSA 2012
Reply
0 Kudos
GMCON
Enthusiast
Enthusiast

Since you have to wait, there is one other thing to check, it is normally set to yes by default but you can check to make sure that under policies for teaming and failover that "Notify Switches" is set.  It is a long shot but it is something to make sure of.  It is normally set at the port group level.

Reply
0 Kudos
MikeF0209
Contributor
Contributor

Yes, this is setup on all VDS for the hosts.  I will try enabeling Port Edge on the Nexus switches to bypass the "learning and listening" phase and go directly into redirecting.  I will have to get this scheduled during a maintenance window coming up.  Will update the thread once its done and tested. 

If anyone else has any input please share Smiley Happy

Thanks

Mike Fernandez Sr. Systems Engineer VCP-DCV5, MCSE 2008, MCSA 2012
Reply
0 Kudos
suhaakin
Contributor
Contributor

Hello All,

Any progress on this? I'm just curious about the solution.

Thanks,

Reply
0 Kudos