Hi,
I'm having an issue with VMotion on one of my nested ESXi 5.1 hosts.
Lab Setup
Physical Host: HP ML350 G6 - (The CPU's are Intel Nahalem L5520 which support Intel VT-x & EPT so they can run 64-Bit nested VM's)
Hypervisor: ESXi 5.1.0 838463
Hostname: ESX1.ESX.COM - 192.168.3.2
Virtual Nested Lab
Hostname: ESXi5-1.ESX.COM: running ESXi 5.1.0 838463 - 192.168.3.70
Hostname: ESXi5-2.ESX.COM: running ESXi 5.1.0 838463 - 192.168.3.71
Cluster has HA & DRS enabled
All network settings are the same on both hosts and connectivity between them is fine and DNS is working as expected.
I currently only have a 32-Bit windows 2003 server VM running on the nested ESXi servers. I can successfully cold migrate between the nested ESXi hosts but when I try and VMotion from ESXi2 > ESXi1 the ESXi1goes into a (not responding) state and sometimes the VM itself goes into this state also.
I then have to reconnect the host in the VI Client. This does not happen when VMotioning to ESXi5-2
VPXD log from vCenter
HostD log from ESXi5-1
2013-02-02T15:51:57.597Z [39F38B90 info 'Vmomi'] Throw vmodl.fault.RequestCanceled
2013-02-02T15:51:57.597Z [39F38B90 info 'Vmomi'] Result:
--> (vmodl.fault.RequestCanceled) {
--> dynamicType = <unset>,
--> faultCause = (vmodl.MethodFault) null,
--> msg = "",
--> }
2013-02-02T15:51:57.598Z [3A1AFB90 error 'SoapAdapter.HTTPService'] HTTP Transaction failed on stream TCP(error:Transport endpoint is not connected) with error N7Vmacore15SystemExceptionE(Connection reset by peer)
2013-02-02T15:53:09.095Z [3A1F0B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
2013-02-02T15:54:40.417Z [FFC40B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
2013-02-02T15:54:49.274Z [39E75B90 verbose 'DvsManager'] PersistAllDvsInfo called
2013-02-02T15:55:01.946Z [39E75B90 verbose 'SoapAdapter'] Responded to service state request
VPXA log from ESXi5-1
2013-02-02T15:45:08.449Z [2203EB90 error 'vmomi.soapStub[1]']
--> Error returned by expat parser: not well-formed (invalid token)
-->
--> while parsing serialized value of type string
--> at line 7, column 3768
-->
--> while parsing property "fullFormattedMessage" of static type string
-->
--> while parsing serialized DataObject of type vim.event.VmMessageWarningEvent
--> at line 7, column 3234
-->
--> error parsing Any with xsiType ArrayOfEvent
--> at line 7, column 403
-->
--> while parsing property "val" of static type anyType
-->
--> while parsing serialized DataObject of type vmodl.query.PropertyCollector.Change
--> at line 7, column 354
-->
--> while parsing property "changeSet" of static type ArrayOfPropertyChange
-->
--> while parsing serialized DataObject of type vmodl.query.PropertyCollector.ObjectUpdate
--> at line 7, column 204
-->
--> while parsing property "objectSet" of static type ArrayOfObjectUpdate
-->
--> while parsing serialized DataObject of type vmodl.query.PropertyCollector.FilterUpdate
--> at line 7, column 73
-->
--> while parsing property "filterSet" of static type ArrayOfPropertyFilterUpdate
-->
--> while parsing serialized DataObject of type vmodl.query.PropertyCollector.UpdateSet
--> at line 7, column 42
-->
--> while parsing return value of type vmodl.query.PropertyCollector.UpdateSet, version vim.version.version8
--> at line 7, column 0
-->
--> while parsing SOAP body
--> at line 6, column 0
-->
--> while parsing SOAP envelope
--> at line 2, column 0
-->
--> while parsing HTTP response for method waitForUpdates
--> on object of type vmodl.query.PropertyCollector
--> at line 1, column 0
2013-02-02T15:45:08.451Z [2203EB90 warning 'Default'] Closing Response processing in unexpected state: 3
2013-02-02T15:45:08.451Z [2203EB90 verbose 'VpxaHalCnxHostagent' opID=WFU-db3997d9] [WaitForUpdatesDone] Received callback
2013-02-02T15:45:08.451Z [2203EB90 error 'VpxaHalCnxHostagent' opID=WFU-db3997d9] [WaitForUpdatesDone] Got error in WaitForUpdates() call to hostd: vmodl.fault.SystemError
2013-02-02T15:45:08.451Z [2203EB90 error 'VpxaHalCnxHostagent' opID=WFU-db3997d9] [WaitForUpdatesDone] Fatal error while listening-for/processing updates from hostd. Backtrace:
--> backtrace[00] rip 10a1d8c3 Vmacore::System::Stacktrace::CaptureWork(unsigned int)
--> backtrace[01] rip 108437d8 Vmacore::System::SystemFactoryImpl::CreateQuickBacktrace(Vmacore::Ref<Vmacore::System::Backtrace>&)
--> backtrace[02] rip 107e2205 Vmacore::Throwable::Throwable(std::string const&)
--> backtrace[03] rip 09eff98c Vmomi::RuntimeFault::Exception::Exception(Vmomi::RuntimeFault*)
--> backtrace[04] rip 10e7b768 Vmomi::SoapScheduledItemImpl::GetResultFromResponse(Vmacore::Http::ClientResponse*, Vmomi::SoapStubAdapterImpl*, Vmacore::Ref<Vmomi::Any>&) const
--> backtrace[05] rip 10e7c315 Vmomi::SoapScheduledItemImpl::RequestCompletedImpl(Vmacore::Exception*, Vmacore::Http::ClientResponse*, Vmacore::Http::PendingRequestItem*)
--> backtrace[06] rip 10e84805 Vmomi::SoapScheduledItemImpl::RequestCompleteParams::Invoke()
--> backtrace[07] rip 10e80e9d boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void, boost::_mfi::mf0<void, Vmomi::SoapScheduledItemImpl::RequestCompleteParams>, boost::_bi::list1<boost::_bi::value<Vmacore::Ref<Vmomi::SoapScheduledItemImpl::RequestCompleteParams> > > >, void>::invoke(boost::detail::function::function_buffer&)
--> backtrace[08] rip 10a3d1b2 Vmacore::System::RegularWork::InvokeWork()
--> backtrace[09] rip 10a330ba Vmacore::System::ThreadPoolPosix::RunWorkerThread()
--> backtrace[10] rip 10a37f6d boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void, boost::_mfi::mf0<void, Vmacore::System::ThreadPoolPosix>, boost::_bi::list1<boost::_bi::value<Vmacore::Ref<Vmacore::System::ThreadPoolPosix> > > >, void>::invoke(boost::detail::function::function_buffer&)
--> backtrace[11] rip 09eda72f boost::function0<void>::operator()() const
--> backtrace[12] rip 10a2c783 Vmacore::System::ThreadPosixPrivate::ThreadBegin(void*)
--> backtrace[13] rip 10497872 /lib/libpthread.so.0 [0x10497872]
--> backtrace[14] rip 1508004e /lib/libc.so.6(clone+0x5e) [0x1508004e]
-->
2013-02-02T15:45:08.465Z [2203EB90 error 'vpxavpxaInvtHostCnx' opID=WFU-db3997d9] [VpxaInvtHost] Can't connect to hostd/serverd. Shutting down...
2013-02-02T15:45:08.466Z [2203EB90 info 'Default' opID=WFU-db3997d9] [Vpxa] Shutting down now
VMKernel log from ESXi5-1
2013-02-02T14:34:50.158Z cpu5:4371)Migrate: vm 4384: 3273: Setting VMOTION info: Source ts = 1359815718260093, src ip = <192.168.3.70> dest ip = <192.168.3.71> Dest wid = 10816 using SHARED swap
2013-02-02T14:34:50.162Z cpu5:4371)Tcpip_Vmk: 1213: Affinitizing 192.168.3.70 to world 12462, Success
2013-02-02T14:34:50.162Z cpu5:4371)VMotion: 2688: 1359815718260093 S: Set ip address '192.168.3.70' worldlet affinity to send World ID 12462
2013-02-02T14:34:50.162Z cpu5:4371)Hbr: 3308: Migration start received (worldID=4384) (migrateType=1) (event=0) (isSource=1) (sharedConfig=1)
2013-02-02T14:34:50.163Z cpu2:2542)MigrateNet: vm 2542: 2061: Accepted connection from <192.168.3.71>
2013-02-02T14:34:50.163Z cpu2:2542)MigrateNet: vm 2542: 2131: dataSocket 0x410006a514a0 receive buffer size is 563272
2013-02-02T14:34:50.164Z cpu6:12462)VMotionUtil: 3184: 1359815718260093 S: Stream connection 1 added.
2013-02-02T14:34:50.164Z cpu6:12462)VMotionUtil: 3184: 1359815718260093 S: Stream connection 2 added.
2013-02-02T14:34:52.032Z cpu5:4384)VMotion: 4417: 1359815718260093 S: Stopping pre-copy: only 655 pages left to send, which can be sent within the switchover time goal of 0.500 seconds (network bandwidth ~224.054 MB/s, 3478246% t2d)
2013-02-02T14:34:52.060Z cpu0:4384)NetPort: 1574: disabled port 0x4000006
2013-02-02T14:34:52.060Z cpu0:4403)VSCSI: 6335: handle 8192(vscsi0:0):Destroying Device for world 4384 (pendCom 0)
2013-02-02T14:34:52.545Z cpu0:12462)VMotionSend: 3640: 1359815718260093 S: Sent all modified pages to destination (network bandwidth ~7.484 MB/s)
2013-02-02T14:34:53.583Z cpu0:4371)Hbr: 3405: Migration end received (worldID=4384) (migrateType=1) (event=1) (isSource=1) (sharedConfig=1)
2013-02-02T14:34:53.588Z cpu0:2083)Net: 2475: disconnected client from port 0x4000006
2013-02-02T14:34:53.920Z cpu3:2963)Config: 347: "SIOControlFlag2" = 0, Old Value: 1, (Status: 0x0)
2013-02-02T14:37:06.676Z cpu1:2049)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x4124007f5000, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T14:37:06.676Z cpu1:2049)ScsiDeviceIO: 2316: Cmd(0x4124007f5000) 0x1a, CmdSN 0x12da from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T14:37:09.686Z cpu1:4405)Config: 347: "SIOControlFlag2" = 1, Old Value: 0, (Status: 0x0)
2013-02-02T14:37:09.742Z cpu7:12787)MemSched: vm 12787: 7756: extended swap to 8192 pgs
2013-02-02T14:37:10.092Z cpu1:12787)World: vm 12824: 1421: Starting world vmm0:CTX2 with flags 8
2013-02-02T14:37:10.092Z cpu1:12787)Sched: vm 12824: 6406: Adding world 'vmm0:CTX2', group 'host/user', cpu: shares=-3 min=0 minLimit=-1 max=-1, mem: shares=-3 min=0 minLimit=-1 max=-1
2013-02-02T14:37:10.092Z cpu1:12787)Sched: vm 12824: 6421: renamed group 17604 to vm.12787
2013-02-02T14:37:10.092Z cpu1:12787)Sched: vm 12824: 6438: group 17604 is located under group 4
2013-02-02T14:37:10.095Z cpu1:12787)MemSched: vm 12787: 7756: extended swap to 23376 pgs
2013-02-02T14:37:10.113Z cpu1:12787)WARNING: MemSched: 6105: Psharing is disabled but balooning is not.
2013-02-02T14:37:10.114Z cpu1:12787)World: vm 12827: 1421: Starting world vmm1:CTX2 with flags 8
2013-02-02T14:37:10.149Z cpu1:12787)Migrate: vm 12824: 3273: Setting VMOTION info: Dest ts = 1359815862529112, src ip = <192.168.3.71> dest ip = <192.168.3.70> Dest wid = 0 using SHARED swap
2013-02-02T14:37:10.154Z cpu1:12787)Tcpip_Vmk: 1213: Affinitizing 192.168.3.70 to world 10790, Success
2013-02-02T14:37:10.154Z cpu1:12787)VMotion: 2688: 1359815862529112 😧 Set ip address '192.168.3.70' worldlet affinity to recv World ID 10790
2013-02-02T14:37:10.154Z cpu1:12787)Hbr: 3308: Migration start received (worldID=12824) (migrateType=1) (event=0) (isSource=0) (sharedConfig=1)
2013-02-02T14:38:28.682Z cpu5:6466)Config: 347: "HostLocalSwapDirEnabled" = 0, Old Value: 0, (Status: 0x0)
2013-02-02T14:39:10.168Z cpu4:12787)WARNING: Migrate: 5235: 1359815862529112 😧 Migration considered a failure by the VMX. It is most likely a timeout, but check the VMX log for the true error.
2013-02-02T14:39:10.168Z cpu4:12787)WARNING: Migrate: 269: 1359815862529112 😧 Failed: Migration determined a failure by the VMX (0xbad0092) @0x4180374a4001
2013-02-02T14:39:10.168Z cpu4:12787)Hbr: 3405: Migration end received (worldID=12824) (migrateType=1) (event=1) (isSource=0) (sharedConfig=1)
2013-02-02T14:39:10.178Z cpu6:6467)Config: 347: "SIOControlFlag2" = 0, Old Value: 1, (Status: 0x0)
2013-02-02T14:39:10.192Z cpu1:3731)DLX: 3661: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode 1] Checking liveness:
2013-02-02T14:39:10.192Z cpu1:3731)[type 10c00001 offset 255346688 v 869, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 606
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T14:39:14.197Z cpu1:3731)DLX: 4185: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode: 1] Not free:
2013-02-02T14:39:14.197Z cpu1:3731)[type 10c00001 offset 255346688 v 869, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 606
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T14:39:14.211Z cpu1:3731)DLX: 3661: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode 1] Checking liveness:
2013-02-02T14:39:14.212Z cpu1:3731)[type 10c00001 offset 255346688 v 869, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 606
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T14:39:18.218Z cpu1:3731)DLX: 4185: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode: 1] Not free:
2013-02-02T14:39:18.218Z cpu1:3731)[type 10c00001 offset 255346688 v 869, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 606
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T14:39:20.272Z cpu6:2963)Config: 347: "VMOverheadGrowthLimit" = -1, Old Value: 0, (Status: 0x0)
2013-02-02T14:39:42.759Z cpu3:2960)Config: 347: "SIOControlFlag2" = 1, Old Value: 0, (Status: 0x0)
2013-02-02T14:39:42.833Z cpu2:13909)MemSched: vm 13909: 7756: extended swap to 8192 pgs
2013-02-02T14:39:43.190Z cpu2:13909)World: vm 13921: 1421: Starting world vmm0:CTX2 with flags 8
2013-02-02T14:39:43.190Z cpu2:13909)Sched: vm 13921: 6406: Adding world 'vmm0:CTX2', group 'host/user', cpu: shares=-3 min=0 minLimit=-1 max=-1, mem: shares=-3 min=0 minLimit=-1 max=-1
2013-02-02T14:39:43.190Z cpu2:13909)Sched: vm 13921: 6421: renamed group 19495 to vm.13909
2013-02-02T14:39:43.190Z cpu2:13909)Sched: vm 13921: 6438: group 19495 is located under group 4
2013-02-02T14:39:43.193Z cpu2:13909)MemSched: vm 13909: 7756: extended swap to 23376 pgs
2013-02-02T14:39:43.212Z cpu2:13909)WARNING: MemSched: 6105: Psharing is disabled but balooning is not.
2013-02-02T14:39:43.213Z cpu2:13909)World: vm 13923: 1421: Starting world vmm1:CTX2 with flags 8
2013-02-02T14:39:43.247Z cpu2:13909)Migrate: vm 13921: 3273: Setting VMOTION info: Dest ts = 1359816015393512, src ip = <192.168.3.71> dest ip = <192.168.3.70> Dest wid = 0 using SHARED swap
2013-02-02T14:39:43.251Z cpu2:13909)Tcpip_Vmk: 1213: Affinitizing 192.168.3.70 to world 13929, Success
2013-02-02T14:39:43.251Z cpu2:13909)VMotion: 2688: 1359816015393512 😧 Set ip address '192.168.3.70' worldlet affinity to recv World ID 13929
2013-02-02T14:39:43.251Z cpu2:13909)Hbr: 3308: Migration start received (worldID=13921) (migrateType=1) (event=0) (isSource=0) (sharedConfig=1)
2013-02-02T14:41:43.258Z cpu7:13909)WARNING: Migrate: 5235: 1359816015393512 😧 Migration considered a failure by the VMX. It is most likely a timeout, but check the VMX log for the true error.
2013-02-02T14:41:43.258Z cpu7:13909)WARNING: Migrate: 269: 1359816015393512 😧 Failed: Migration determined a failure by the VMX (0xbad0092) @0x4180374a4001
2013-02-02T14:41:43.258Z cpu7:13909)Hbr: 3405: Migration end received (worldID=13921) (migrateType=1) (event=1) (isSource=0) (sharedConfig=1)
2013-02-02T14:41:43.268Z cpu6:13538)Config: 347: "SIOControlFlag2" = 0, Old Value: 1, (Status: 0x0)
2013-02-02T14:41:43.279Z cpu3:3731)DLX: 3661: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode 1] Checking liveness:
2013-02-02T14:41:43.279Z cpu3:3731)[type 10c00001 offset 255346688 v 889, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 748
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T14:41:47.284Z cpu3:3731)DLX: 4185: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode: 1] Not free:
2013-02-02T14:41:47.284Z cpu3:3731)[type 10c00001 offset 255346688 v 889, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 748
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T14:41:47.298Z cpu3:3731)DLX: 3661: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode 1] Checking liveness:
2013-02-02T14:41:47.298Z cpu3:3731)[type 10c00001 offset 255346688 v 889, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 748
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T14:41:51.303Z cpu3:3731)DLX: 4185: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode: 1] Not free:
2013-02-02T14:41:51.303Z cpu3:3731)[type 10c00001 offset 255346688 v 889, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 748
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T14:42:06.680Z cpu1:2049)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x412400804100, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T14:42:06.680Z cpu1:2049)ScsiDeviceIO: 2316: Cmd(0x412400804100) 0x1a, CmdSN 0x1520 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T14:44:41.290Z cpu5:2053)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x85 (0x412400804300, 3084) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T14:44:41.290Z cpu5:2053)ScsiDeviceIO: 2316: Cmd(0x412400804300) 0x85, CmdSN 0xf from world 3084 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T14:44:41.291Z cpu5:2427)ScsiDeviceIO: 2316: Cmd(0x412400804300) 0x4d, CmdSN 0x10 from world 3084 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T14:44:41.291Z cpu5:2427)ScsiDeviceIO: 2316: Cmd(0x412400804300) 0x1a, CmdSN 0x11 from world 3084 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x24 0x0.
2013-02-02T14:47:06.679Z cpu1:2168)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x4124007dc040, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T14:47:06.679Z cpu1:2168)ScsiDeviceIO: 2316: Cmd(0x4124007dc040) 0x1a, CmdSN 0x1544 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T14:48:05.819Z cpu7:2963)Config: 347: "HostLocalSwapDirEnabled" = 0, Old Value: 0, (Status: 0x0)
2013-02-02T14:52:06.677Z cpu2:2050)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x412400813ec0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T14:52:06.677Z cpu2:2050)ScsiDeviceIO: 2316: Cmd(0x412400813ec0) 0x1a, CmdSN 0x1570 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T14:56:06.064Z cpu4:15497)NMP: nmpStateLogger:3160: NMP module ID: 2b.
2013-02-02T14:56:06.064Z cpu4:15497)NMP: nmpStateLogger:3161: NMP heap ID: 0x4100131e0000.
2013-02-02T14:56:06.064Z cpu4:15497)NMP: nmpStateLogger:3162: NMP slab ID: 0x410012e85b80.
2013-02-02T14:56:06.064Z cpu4:15497)NMP: nmpStateLogger:3174: NMP is managing 15 devices:
2013-02-02T14:56:44.780Z cpu3:15502)FS3Misc: 1465: Long VMFS rsv time on 'Iomega-iSCSI-Prod2' (held for 398 msecs). # R: 1, # W: 1 bytesXfer: 9 sectors
2013-02-02T14:56:59.985Z cpu4:15571)FS3Misc: 1465: Long VMFS rsv time on 'Iomega-iSCSI-Prod2' (held for 311 msecs). # R: 1, # W: 1 bytesXfer: 3 sectors
2013-02-02T14:57:07.385Z cpu3:2051)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x412400789dc0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T14:57:07.385Z cpu3:2051)ScsiDeviceIO: 2316: Cmd(0x412400789dc0) 0x1a, CmdSN 0x17bc from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T14:57:15.273Z cpu6:15584)NMP: nmpStateLogger:3160: NMP module ID: 2b.
2013-02-02T14:57:15.273Z cpu6:15584)NMP: nmpStateLogger:3161: NMP heap ID: 0x4100131e0000.
2013-02-02T14:57:15.273Z cpu6:15584)NMP: nmpStateLogger:3162: NMP slab ID: 0x410012e85b80.
2013-02-02T14:57:15.273Z cpu6:15584)NMP: nmpStateLogger:3174: NMP is managing 15 devices:
2013-02-02T14:58:47.679Z cpu6:16234)BC: 3115: Blocking due to no free buffers. nDirty = 265 nWaiters = 1
2013-02-02T14:58:47.679Z cpu6:16234)BC: 3115: Blocking due to no free buffers. nDirty = 265 nWaiters = 1
2013-02-02T14:58:47.679Z cpu3:2425)BC: 3115: Blocking due to no free buffers. nDirty = 265 nWaiters = 2
2013-02-02T14:59:07.769Z cpu7:16317)Config: 347: "NetTraceEnable" = 1, Old Value: 0, (Status: 0x0)
2013-02-02T14:59:07.772Z cpu7:16317)Config: 347: "NetTraceEnable" = 0, Old Value: 1, (Status: 0x0)
2013-02-02T14:59:07.772Z cpu7:16317)Config: 347: "NetTraceEnable" = 0, Old Value: 0, (Status: 0x0)
2013-02-02T14:59:34.109Z cpu3:2051)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x85 (0x41240080b5c0, 16514) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T14:59:34.109Z cpu3:2051)ScsiDeviceIO: 2316: Cmd(0x41240080b5c0) 0x85, CmdSN 0x12 from world 16514 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T14:59:34.110Z cpu3:2051)ScsiDeviceIO: 2316: Cmd(0x41240080b5c0) 0x4d, CmdSN 0x13 from world 16514 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T14:59:34.110Z cpu3:2051)ScsiDeviceIO: 2316: Cmd(0x41240080b5c0) 0x1a, CmdSN 0x14 from world 16514 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x24 0x0.
2013-02-02T15:02:06.679Z cpu0:2168)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x412400811ec0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:02:06.679Z cpu0:2168)ScsiDeviceIO: 2316: Cmd(0x412400811ec0) 0x1a, CmdSN 0x1da8 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:07:06.712Z cpu2:2050)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x4124008092c0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:07:06.712Z cpu2:2050)ScsiDeviceIO: 2316: Cmd(0x4124008092c0) 0x1a, CmdSN 0x1dc5 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:12:06.676Z cpu0:2056)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x41240078b4c0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:12:06.676Z cpu0:2056)ScsiDeviceIO: 2316: Cmd(0x41240078b4c0) 0x1a, CmdSN 0x1de2 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:14:41.348Z cpu6:2054)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x85 (0x412400778340, 3084) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:14:41.348Z cpu6:2054)ScsiDeviceIO: 2316: Cmd(0x412400778340) 0x85, CmdSN 0x15 from world 3084 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:14:41.348Z cpu6:2427)ScsiDeviceIO: 2316: Cmd(0x412400778340) 0x4d, CmdSN 0x16 from world 3084 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:14:41.348Z cpu6:2427)ScsiDeviceIO: 2316: Cmd(0x412400778340) 0x1a, CmdSN 0x17 from world 3084 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x24 0x0.
2013-02-02T15:17:06.677Z cpu2:2050)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x412400775780, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:17:06.677Z cpu2:2050)ScsiDeviceIO: 2316: Cmd(0x412400775780) 0x1a, CmdSN 0x1e06 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:22:06.680Z cpu0:2056)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x4124007a92c0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:22:06.680Z cpu0:2056)ScsiDeviceIO: 2316: Cmd(0x4124007a92c0) 0x1a, CmdSN 0x1e23 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:27:06.677Z cpu3:2051)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x4124007c1e00, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:27:06.677Z cpu3:2051)ScsiDeviceIO: 2316: Cmd(0x4124007c1e00) 0x1a, CmdSN 0x1e60 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:32:06.679Z cpu1:2139)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x4124007cdac0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:32:06.679Z cpu1:2139)ScsiDeviceIO: 2316: Cmd(0x4124007cdac0) 0x1a, CmdSN 0x1e7d from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:37:06.677Z cpu3:2051)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x41240078a7c0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:37:06.677Z cpu3:2051)ScsiDeviceIO: 2316: Cmd(0x41240078a7c0) 0x1a, CmdSN 0x1e9a from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:42:06.674Z cpu2:2050)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x4124007adac0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:42:06.674Z cpu2:2050)ScsiDeviceIO: 2316: Cmd(0x4124007adac0) 0x1a, CmdSN 0x1eb7 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:44:41.390Z cpu6:2054)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x85 (0x4124007f5b00, 3084) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:44:41.390Z cpu6:2054)ScsiDeviceIO: 2316: Cmd(0x4124007f5b00) 0x85, CmdSN 0x18 from world 3084 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:44:41.391Z cpu6:2427)ScsiDeviceIO: 2316: Cmd(0x4124007f5b00) 0x4d, CmdSN 0x19 from world 3084 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:44:41.391Z cpu6:2427)ScsiDeviceIO: 2316: Cmd(0x4124007f5b00) 0x1a, CmdSN 0x1a from world 3084 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x24 0x0.
2013-02-02T15:44:48.344Z cpu0:6467)Config: 347: "SIOControlFlag2" = 1, Old Value: 0, (Status: 0x0)
2013-02-02T15:44:48.454Z cpu7:6257)MemSched: vm 6257: 7756: extended swap to 8192 pgs
2013-02-02T15:44:48.806Z cpu6:6257)World: vm 18568: 1421: Starting world vmm0:CTX2 with flags 8
2013-02-02T15:44:48.806Z cpu6:6257)Sched: vm 18568: 6406: Adding world 'vmm0:CTX2', group 'host/user', cpu: shares=-3 min=0 minLimit=-1 max=-1, mem: shares=-3 min=0 minLimit=-1 max=-1
2013-02-02T15:44:48.806Z cpu6:6257)Sched: vm 18568: 6421: renamed group 26863 to vm.6257
2013-02-02T15:44:48.806Z cpu6:6257)Sched: vm 18568: 6438: group 26863 is located under group 4
2013-02-02T15:44:48.810Z cpu6:6257)MemSched: vm 6257: 7756: extended swap to 23376 pgs
2013-02-02T15:44:48.829Z cpu6:6257)WARNING: MemSched: 6105: Psharing is disabled but balooning is not.
2013-02-02T15:44:48.830Z cpu6:6257)World: vm 18570: 1421: Starting world vmm1:CTX2 with flags 8
2013-02-02T15:44:48.868Z cpu6:6257)Migrate: vm 18568: 3273: Setting VMOTION info: Dest ts = 1359819920681912, src ip = <192.168.3.71> dest ip = <192.168.3.70> Dest wid = 0 using SHARED swap
2013-02-02T15:44:48.874Z cpu6:6257)Tcpip_Vmk: 1213: Affinitizing 192.168.3.70 to world 18580, Success
2013-02-02T15:44:48.874Z cpu6:6257)VMotion: 2688: 1359819920681912 😧 Set ip address '192.168.3.70' worldlet affinity to recv World ID 18580
2013-02-02T15:44:48.874Z cpu6:6257)Hbr: 3308: Migration start received (worldID=18568) (migrateType=1) (event=0) (isSource=0) (sharedConfig=1)
2013-02-02T15:46:48.890Z cpu1:6257)WARNING: Migrate: 5235: 1359819920681912 😧 Migration considered a failure by the VMX. It is most likely a timeout, but check the VMX log for the true error.
2013-02-02T15:46:48.890Z cpu1:6257)WARNING: Migrate: 269: 1359819920681912 😧 Failed: Migration determined a failure by the VMX (0xbad0092) @0x4180374a4001
2013-02-02T15:46:48.890Z cpu1:6257)Hbr: 3405: Migration end received (worldID=18568) (migrateType=1) (event=1) (isSource=0) (sharedConfig=1)
2013-02-02T15:46:48.899Z cpu7:2960)Config: 347: "SIOControlFlag2" = 0, Old Value: 1, (Status: 0x0)
2013-02-02T15:46:48.911Z cpu5:3731)DLX: 3661: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode 1] Checking liveness:
2013-02-02T15:46:48.911Z cpu5:3731)[type 10c00001 offset 255346688 v 909, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 1030
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T15:46:52.916Z cpu5:3731)DLX: 4185: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode: 1] Not free:
2013-02-02T15:46:52.916Z cpu5:3731)[type 10c00001 offset 255346688 v 909, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 1030
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T15:46:52.930Z cpu5:3731)DLX: 3661: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode 1] Checking liveness:
2013-02-02T15:46:52.930Z cpu5:3731)[type 10c00001 offset 255346688 v 909, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 1030
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T15:46:56.935Z cpu5:3731)DLX: 4185: vol 'Iomega-Dev-iSCSI-1', lock at 255346688: [Req mode: 1] Not free:
2013-02-02T15:46:56.935Z cpu5:3731)[type 10c00001 offset 255346688 v 909, hb offset 3461120
gen 231, mode 1, owner 510d0323-56189feb-abd0-005056b96521 mtime 1030
num 0 gblnum 0 gblgen 0 gblbrk 0]
2013-02-02T15:47:06.678Z cpu2:2050)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x41240080aac0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:47:06.678Z cpu2:2050)ScsiDeviceIO: 2316: Cmd(0x41240080aac0) 0x1a, CmdSN 0x1fb1 from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:52:06.675Z cpu1:2049)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x4124007e8580, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:52:06.675Z cpu1:2049)ScsiDeviceIO: 2316: Cmd(0x4124007e8580) 0x1a, CmdSN 0x1fce from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2013-02-02T15:57:06.679Z cpu1:2049)NMP: nmp_ThrottleLogForDevice:2319: Cmd 0x1a (0x4124007cbfc0, 0) to dev "mpx.vmhba32:C0:T0:L0" on path "vmhba32:C0:T0:L0" Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0. Act:NONE
2013-02-02T15:57:06.679Z cpu1:2049)ScsiDeviceIO: 2316: Cmd(0x4124007cbfc0) 0x1a, CmdSN 0x1ffa from world 0 to dev "mpx.vmhba32:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
VMware Log extracted from the physical ESXi host for nested VM ESXi5-1
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_SHPC_MemReg : 2 2 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_SVGAFB : 1024 1024 | 1024 1024 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_SVGAMEM : 64 64 | 64 64 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_HDAudioReg : 3 3 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_EHCIRegister : 1 1 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_XhciRegister : 1 1 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_PhysMemDebug : 0 0 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_HVIOBitmap : 3 3 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_HVMSRBitmap : 2 2 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_VHVRootMSRBitmap : 2 2 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_VHVGuestMSRBitmap : 2 2 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_vhvCachedVMCS : 8 8 | 8 8 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_StateLoggerLogBuf : 0 0 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_DebugStubSSEvents : 8 8 | 1 1 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_DebugStubBWPEvents : 8 8 | 1 1 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_PCIP : 0 0 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_VMsafe : 0 0 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_MonWired : 8 8 | 8 8 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_MonLow : 0 0 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_MonWiredNuma : 208 208 | 208 208 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_MonNuma : 505 505 | 505 505 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_MonOther : 136 136 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_SVMLowMem : 9 9 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_PAEShadow : 8 8 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem OvhdUser_FTCpt : 0 0 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdMem Total nonpaged : 2628 2628 | 2323 2323 0
2013-02-02T12:12:01.208Z| vmx| I120:
2013-02-02T12:12:01.208Z| vmx| I120: reserved | used
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon anonymous cur max | cur max avg
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_Alloc : 376 376 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_BusMemFrame : 4347 4347 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_BusMemFramePGAR : 62 62 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_BusMemMMTracePGAR : 8 8 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_BusMem2MRegionPGAR : 32 32 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_BusMemZapListMPN : 1 1 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_MMU : 400 400 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_ScratchAS : 96 96 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_MonTLB : 48 48 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_DT : 0 0 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_TCCoherency : 168 168 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_TC : 4096 4096 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_ChainInfo : 0 0 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_Island : 8 8 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_BusMemScratchAS : 124 124 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_PlatformScratchAS : 0 0 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_BackdoorHintsMPN : 9 9 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_HV : 8 8 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_VNPTShadow : 5200 5200 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_VNPTShadowCache : 44 44 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_VNPTBackmap : 4110 4110 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_SVMIDT : 8 8 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_CallStackProfAnon : 0 0 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_Numa : 1410 1410 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_WiredNuma : 208 208 | 0 0 0
2013-02-02T12:12:01.208Z| vmx| I120: OvhdAnon OvhdMon_GPhysTraced : 849 849 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_GPhysHWMMU : 4261 4261 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_GPhysNoTrace : 212 212 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_BTScratchPage : 1 1 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_StateLoggerBufferPA : 1 1 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_TraceALot : 0 0 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_VIDE : 4 4 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_VMXNETWake : 0 0 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_BusLogic : 8 8 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_PVSCSIShadowRing : 0 0 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_LSIRings : 8 8 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_FTCptScratchAS : 0 0 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon OvhdMon_VProbe : 1 1 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120: OvhdAnon Total anonymous : 26108 26108 | 0 0 0
2013-02-02T12:12:01.209Z| vmx| I120:
2013-02-02T12:12:01.209Z| vmx| I120: OvhdMem: memsize 8192 MB VMK fixed 74 pages var 0 pages cbrcOverhead 0 pages total 4174 pages
2013-02-02T12:12:01.209Z| vmx| I120: VMMEM: Precise Reservation: 205MB (MainMem=8192MB SVGA=4MB) VMK=16MB
2013-02-02T12:12:01.209Z| vmx| I120: Vix: [11607 mainDispatch.c:991]: VMAutomation_PowerOn. Powering on.
2013-02-02T12:12:01.211Z| vmx| I120: VMX_PowerOn: ModuleTable_PowerOn = 1
2013-02-02T12:12:01.247Z| vcpu-0| I120: VTHREAD start thread 3 "vcpu-0" pid 11623
2013-02-02T12:12:01.247Z| vcpu-0| I120: VMMon_Start: vcpu-0: worldID=11609
2013-02-02T12:12:01.247Z| vcpu-0| I120: APIC: version = 0x15, max LVT = 6
2013-02-02T12:12:01.247Z| vcpu-0| I120: APIC: LDR = 0x40000000, DFR = 0xffffffff
2013-02-02T12:12:01.252Z| vcpu-0| I120: LSI:Initialize adapter scsi0
2013-02-02T12:12:01.253Z| vcpu-0| I120: CPU reset: hard (mode 2)
2013-02-02T12:12:01.253Z| vcpu-0| I120: PIIX4: PM Resuming from suspend type 0x0, chipset.onlineStandby 1
2013-02-02T12:12:01.256Z| vcpu-0| I120: Intel VT: FlexPriority enabled.
2013-02-02T12:12:01.256Z| vcpu-0| I120: Intel VT: VPID enabled.
2013-02-02T12:12:01.256Z| vcpu-0| I120: Intel VT enabled.
2013-02-02T12:12:01.258Z| vcpu-1| I120: VTHREAD start thread 4 "vcpu-1" pid 11624
2013-02-02T12:12:01.258Z| vcpu-1| I120: VMMon_Start: vcpu-1: worldID=11611
2013-02-02T12:12:01.259Z| vcpu-2| I120: VTHREAD start thread 5 "vcpu-2" pid 11625
2013-02-02T12:12:01.259Z| vcpu-2| I120: VMMon_Start: vcpu-2: worldID=11612
2013-02-02T12:12:01.259Z| vcpu-3| I120: VTHREAD start thread 6 "vcpu-3" pid 11626
2013-02-02T12:12:01.259Z| vcpu-3| I120: VMMon_Start: vcpu-3: worldID=11613
2013-02-02T12:12:01.261Z| vcpu-4| I120: VTHREAD start thread 7 "vcpu-4" pid 11627
2013-02-02T12:12:01.261Z| vcpu-4| I120: VMMon_Start: vcpu-4: worldID=11614
2013-02-02T12:12:01.266Z| vcpu-5| I120: VTHREAD start thread 8 "vcpu-5" pid 11628
2013-02-02T12:12:01.266Z| vcpu-5| I120: VMMon_Start: vcpu-5: worldID=11615
2013-02-02T12:12:01.266Z| vcpu-6| I120: VTHREAD start thread 9 "vcpu-6" pid 11629
2013-02-02T12:12:01.267Z| vcpu-6| I120: VMMon_Start: vcpu-6: worldID=11616
2013-02-02T12:12:01.268Z| vcpu-7| I120: VTHREAD start thread 10 "vcpu-7" pid 11630
2013-02-02T12:12:01.268Z| vcpu-7| I120: VMMon_Start: vcpu-7: worldID=11617
2013-02-02T12:12:01.268Z| vcpu-0| I120: Vix: [11623 mainDispatch.c:3867]: VMAutomation_ReportPowerOpFinished: statevar=0, newAppState=1872, success=1 additionalError=0
2013-02-02T12:12:01.289Z| vcpu-0| I120: Vix: [11623 mainDispatch.c:3787]: VMAutomationReportPowerStateChange: Reporting power state change (opcode=0, err=0).
2013-02-02T12:12:01.289Z| vcpu-0| I120: Vix: [11623 mainDispatch.c:3787]: VMAutomationReportPowerStateChange: Reporting power state change (opcode=2, err=0).
2013-02-02T12:12:01.289Z| vcpu-0| I120: Transitioned vmx/execState/val to poweredOn
2013-02-02T12:12:01.289Z| vcpu-1| I120: APIC: version = 0x15, max LVT = 6
2013-02-02T12:12:01.289Z| vcpu-1| I120: APIC: LDR = 0x8000000, DFR = 0xffffffff
2013-02-02T12:12:01.289Z| vcpu-2| I120: APIC: version = 0x15, max LVT = 6
2013-02-02T12:12:01.289Z| vcpu-3| I120: APIC: version = 0x15, max LVT = 6
2013-02-02T12:12:01.289Z| vcpu-4| I120: APIC: version = 0x15, max LVT = 6
2013-02-02T12:12:01.289Z| vcpu-6| I120: APIC: version = 0x15, max LVT = 6
2013-02-02T12:12:01.289Z| vcpu-4| I120: APIC: LDR = 0x80000000, DFR = 0xffffffff
2013-02-02T12:12:01.289Z| vcpu-6| I120: APIC: LDR = 0x80000000, DFR = 0xffffffff
2013-02-02T12:12:01.289Z| vcpu-2| I120: APIC: LDR = 0x10000000, DFR = 0xffffffff
2013-02-02T12:12:01.289Z| vcpu-7| I120: APIC: version = 0x15, max LVT = 6
2013-02-02T12:12:01.289Z| vcpu-5| I120: APIC: version = 0x15, max LVT = 6
2013-02-02T12:12:01.289Z| vcpu-3| I120: APIC: LDR = 0x40000000, DFR = 0xffffffff
2013-02-02T12:12:01.289Z| vcpu-5| I120: APIC: LDR = 0x80000000, DFR = 0xffffffff
2013-02-02T12:12:01.289Z| vcpu-7| I120: APIC: LDR = 0x80000000, DFR = 0xffffffff
2013-02-02T12:12:01.301Z| vcpu-1| I120: CPU reset: hard (mode 2)
2013-02-02T12:12:01.301Z| vcpu-3| I120: CPU reset: hard (mode 2)
2013-02-02T12:12:01.301Z| vcpu-2| I120: CPU reset: hard (mode 2)
2013-02-02T12:12:01.301Z| vcpu-1| I120: Intel VT: FlexPriority enabled.
2013-02-02T12:12:01.301Z| vcpu-1| I120: Intel VT: VPID enabled.
2013-02-02T12:12:01.301Z| vcpu-4| I120: CPU reset: hard (mode 2)
2013-02-02T12:12:01.301Z| vcpu-5| I120: CPU reset: hard (mode 2)
2013-02-02T12:12:01.301Z| vcpu-6| I120: CPU reset: hard (mode 2)
2013-02-02T12:12:01.301Z| vcpu-7| I120: CPU reset: hard (mode 2)
2013-02-02T12:12:01.301Z| vcpu-2| I120: Intel VT: FlexPriority enabled.
2013-02-02T12:12:01.301Z| vcpu-3| I120: Intel VT: FlexPriority enabled.
2013-02-02T12:12:01.301Z| vcpu-1| I120: Intel VT enabled.
2013-02-02T12:12:01.301Z| vcpu-4| I120: Intel VT: FlexPriority enabled.
2013-02-02T12:12:01.301Z| vcpu-2| I120: Intel VT: VPID enabled.
2013-02-02T12:12:01.301Z| vcpu-5| I120: Intel VT: FlexPriority enabled.
2013-02-02T12:12:01.302Z| vcpu-3| I120: Intel VT: VPID enabled.
2013-02-02T12:12:01.302Z| vcpu-6| I120: Intel VT: FlexPriority enabled.
2013-02-02T12:12:01.302Z| vcpu-7| I120: Intel VT: FlexPriority enabled.
2013-02-02T12:12:01.302Z| vcpu-3| I120: Intel VT enabled.
2013-02-02T12:12:01.302Z| vcpu-7| I120: Intel VT: VPID enabled.
2013-02-02T12:12:01.302Z| vcpu-2| I120: Intel VT enabled.
2013-02-02T12:12:01.302Z| vcpu-6| I120: Intel VT: VPID enabled.
2013-02-02T12:12:01.302Z| vcpu-4| I120: Intel VT: VPID enabled.
2013-02-02T12:12:01.302Z| vcpu-5| I120: Intel VT: VPID enabled.
2013-02-02T12:12:01.302Z| vcpu-6| I120: Intel VT enabled.
2013-02-02T12:12:01.302Z| vcpu-4| I120: Intel VT enabled.
2013-02-02T12:12:01.302Z| vcpu-7| I120: Intel VT enabled.
2013-02-02T12:12:01.302Z| vcpu-5| I120: Intel VT enabled.
2013-02-02T12:12:01.306Z| vcpu-5| I120: VMM initialized.
2013-02-02T12:12:01.306Z| vcpu-6| I120: VMM initialized.
2013-02-02T12:12:01.306Z| vcpu-1| I120: VMM initialized.
2013-02-02T12:12:01.306Z| vcpu-4| I120: VMM initialized.
2013-02-02T12:12:01.306Z| vcpu-2| I120: VMM initialized.
2013-02-02T12:12:01.307Z| vcpu-7| I120: VMM initialized.
2013-02-02T12:12:01.307Z| vcpu-3| I120: VMM initialized.
2013-02-02T12:12:01.307Z| vcpu-0| I120: VMM initialized.
2013-02-02T12:12:01.312Z| vmx| I120: Vix: [11607 vigorCommands.c:912]: VigorHotPlugManagerEndBatchCommandCallback: vmdbErr = -24
2013-02-02T12:12:01.314Z| vcpu-1| I120: Monitor has started
2013-02-02T12:12:01.314Z| vcpu-0| I120: Monitor has started
2013-02-02T12:12:01.314Z| vcpu-4| I120: Monitor has started
2013-02-02T12:12:01.314Z| vcpu-3| I120: Monitor has started
2013-02-02T12:12:01.314Z| vcpu-5| I120: Monitor has started
2013-02-02T12:12:01.314Z| vcpu-2| I120: Monitor has started
2013-02-02T12:12:01.314Z| vcpu-7| I120: Monitor has started
2013-02-02T12:12:01.314Z| vcpu-6| I120: Monitor has started
2013-02-02T12:12:01.328Z| vcpu-0| I120: MonitorInitNumaUnmapVMM
2013-02-02T12:12:01.881Z| vcpu-0| I120: SVGA: Registering MemSpace at 0xd8000000(0x0) and 0xd0800000(0x0)
2013-02-02T12:12:01.888Z| vcpu-0| I120: SVGA: Unregistering MemSpace at 0xd8000000(0xd8000000) and 0xd0800000(0xd0800000)
2013-02-02T12:12:02.154Z| vcpu-0| I120: SVGA: Registering MemSpace at 0xd8000000(0xd8000000) and 0xd0800000(0xd0800000)
2013-02-02T12:12:02.166Z| vcpu-0| I120: SVGA: Unregistering MemSpace at 0xd8000000(0xd8000000) and 0xd0800000(0xd0800000)
2013-02-02T12:12:02.167Z| vcpu-0| I120: SVGA: Registering IOSpace at 0x10d0
2013-02-02T12:12:02.168Z| vcpu-0| I120: SVGA: Registering MemSpace at 0xd8000000(0xd8000000) and 0xd0800000(0xd0800000)
2013-02-02T12:12:02.176Z| vcpu-0| I120: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.177Z| vcpu-0| I120: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.179Z| vcpu-0| I120: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.181Z| vcpu-0| I120: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.182Z| vcpu-0| I120: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.184Z| vcpu-0| I120: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.186Z| vcpu-0| I120: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.187Z| vcpu-0| I120: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.189Z| vcpu-0| I120: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.191Z| vcpu-0| I120: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.192Z| vcpu-0| I120: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.194Z| vcpu-0| I120: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.195Z| vcpu-0| I120: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.197Z| vcpu-0| I120: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.199Z| vcpu-0| I120: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.200Z| vcpu-0| I120: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.202Z| vcpu-0| I120: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.204Z| vcpu-0| I120: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.205Z| vcpu-0| I120: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.207Z| vcpu-0| I120: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.209Z| vcpu-0| I120: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.210Z| vcpu-0| I120: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.212Z| vcpu-0| I120: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.213Z| vcpu-0| I120: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.215Z| vcpu-0| I120: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.217Z| vcpu-0| I120: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.218Z| vcpu-0| I120: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.220Z| vcpu-0| I120: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.222Z| vcpu-0| I120: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.223Z| vcpu-0| I120: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.225Z| vcpu-0| I120: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.227Z| vcpu-0| I120: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.231Z| vcpu-1| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:02.238Z| vcpu-2| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:02.244Z| vcpu-3| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:02.250Z| vcpu-4| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:02.256Z| vcpu-5| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:02.263Z| vcpu-6| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:02.269Z| vcpu-7| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:02.574Z| vcpu-0| I120: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.576Z| vcpu-0| I120: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.577Z| vcpu-0| I120: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.579Z| vcpu-0| I120: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.580Z| vcpu-0| I120: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.582Z| vcpu-0| I120: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.583Z| vcpu-0| I120: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.585Z| vcpu-0| I120: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.587Z| vcpu-0| I120: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.588Z| vcpu-0| I120: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.590Z| vcpu-0| I120: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.591Z| vcpu-0| I120: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.593Z| vcpu-0| I120: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.594Z| vcpu-0| I120: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.596Z| vcpu-0| I120: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.598Z| vcpu-0| I120: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.599Z| vcpu-0| I120: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.601Z| vcpu-0| I120: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.602Z| vcpu-0| I120: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.604Z| vcpu-0| I120: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.605Z| vcpu-0| I120: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.607Z| vcpu-0| I120: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.609Z| vcpu-0| I120: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.610Z| vcpu-0| I120: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.612Z| vcpu-0| I120: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.613Z| vcpu-0| I120: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.615Z| vcpu-0| I120: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.616Z| vcpu-0| I120: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.618Z| vcpu-0| I120: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.620Z| vcpu-0| I120: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.621Z| vcpu-0| I120: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.623Z| vcpu-0| I120: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)
2013-02-02T12:12:02.644Z| vcpu-0| I120: DISKUTIL: scsi0:0 : geometry=1044/255/63
2013-02-02T12:12:02.646Z| vcpu-0| I120: DISKUTIL: scsi0:0 : capacity=16777216
2013-02-02T12:12:03.847Z| vcpu-1| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:03.856Z| vcpu-2| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:03.865Z| vcpu-3| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:03.873Z| vcpu-4| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:03.878Z| vcpu-5| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:03.884Z| vcpu-6| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:03.889Z| vcpu-7| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:03.959Z| vcpu-0| I120: BIOS-UUID is 56 4d 22 4f e9 c6 4c a8-be da c0 c2 2a 97 05 fa
2013-02-02T12:12:04.509Z| vcpu-0| I120: SVGA enabling SVGA
2013-02-02T12:12:40.282Z| vcpu-0| I120: APIC THERMLVT write: 0xfc
2013-02-02T12:12:40.410Z| vcpu-1| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:40.421Z| vcpu-1| I120: APIC THERMLVT write: 0xfc
2013-02-02T12:12:40.423Z| vcpu-2| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:40.434Z| vcpu-2| I120: APIC THERMLVT write: 0xfc
2013-02-02T12:12:40.436Z| vcpu-3| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:40.447Z| vcpu-3| I120: APIC THERMLVT write: 0xfc
2013-02-02T12:12:40.449Z| vcpu-4| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:40.460Z| vcpu-4| I120: APIC THERMLVT write: 0xfc
2013-02-02T12:12:40.461Z| vcpu-5| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:40.473Z| vcpu-5| I120: APIC THERMLVT write: 0xfc
2013-02-02T12:12:40.474Z| vcpu-6| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:40.485Z| vcpu-6| I120: APIC THERMLVT write: 0xfc
2013-02-02T12:12:40.486Z| vcpu-7| I120: CPU reset: soft (mode 2)
2013-02-02T12:12:40.497Z| vcpu-7| I120: APIC THERMLVT write: 0xfc
2013-02-02T12:12:43.540Z| vcpu-0| I120: SVGA: Unregistering IOSpace at 0x10d0
2013-02-02T12:12:43.540Z| vcpu-0| I120: SVGA: Unregistering MemSpace at 0xd8000000(0xd8000000) and 0xd0800000(0xd0800000)
2013-02-02T12:12:43.547Z| vcpu-0| I120: SVGA: Registering IOSpace at 0x10d0
2013-02-02T12:12:43.547Z| vcpu-0| I120: SVGA: Registering MemSpace at 0xd8000000(0xd8000000) and 0xd0800000(0xd0800000)
2013-02-02T12:13:01.296Z| vmx| I120: GuestRpcSendTimedOut: message to toolbox-dnd timed out.
2013-02-02T12:14:46.224Z| vcpu-0| I120: HBACommon: First write on scsi0:0.fileName='/vmfs/volumes/37e990a4-5ec929a3/ESXi5-1_1/ESXi5-1_1.vmdk'
2013-02-02T12:14:46.225Z| vcpu-0| I120: DDB: "longContentID" = "da5a345e786673baeb788d4419d1d673" (was "f1a5ca0a1f444c81194b21133db1d88e")
2013-02-02T12:14:46.264Z| vcpu-0| I120: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x3db1d88e, new=0x19d1d673 (da5a345e786673baeb788d4419d1d673)
2013-02-02T12:15:01.315Z| vmx| I120: GuestRpcSendTimedOut: message to toolbox timed out.
2013-02-02T12:15:01.315Z| vmx| I120: Vix: [11607 guestCommands.c:1926]: Error VIX_E_TOOLS_NOT_RUNNING in VMAutomationTranslateGuestRpcError(): VMware Tools are not running in the guest
2013-02-02T12:19:12.735Z| vcpu-1| I120: Intel VT: FlexPriority disabled.
2013-02-02T12:19:12.735Z| vcpu-2| I120: Intel VT: FlexPriority disabled.
2013-02-02T12:19:12.735Z| vcpu-5| I120: Intel VT: FlexPriority disabled.
2013-02-02T12:19:12.735Z| vcpu-4| I120: Intel VT: FlexPriority disabled.
2013-02-02T12:19:12.735Z| vcpu-6| I120: Intel VT: FlexPriority disabled.
2013-02-02T12:19:12.736Z| vcpu-3| I120: Intel VT: FlexPriority disabled.
2013-02-02T12:19:12.736Z| vcpu-7| I120: Intel VT: FlexPriority disabled.
2013-02-02T12:19:12.736Z| vcpu-0| I120: Intel VT: FlexPriority disabled.
2013-02-02T12:22:01.149Z| vmx| I120: Tools: No activity for 10 minutes, resetting Tools version.
2013-02-02T12:22:01.149Z| vmx| I120: ToolsSetVersionWork did nothing; new tools version (0) matches old Tools version
2013-02-02T14:56:39.726Z| vcpu-6| W110: CDROM ide1:0: Allowing unknown command LOG SENSE (0x4d). --ok
2013-02-02T14:56:39.727Z| vcpu-6| I120: CDROM: Unknown command 0x4D.
2013-02-02T14:56:39.727Z| vcpu-6| I120: CDROM ide1:0: CMD 0x4d (LOG SENSE) FAILED (key 0x5 asc 0x20 ascq 0)
2013-02-02T14:57:48.924Z| vcpu-4| W110: CDROM ide1:0: Allowing unknown command LOG SENSE (0x4d). --ok
2013-02-02T14:57:48.925Z| vcpu-4| I120: CDROM: Unknown command 0x4D.
2013-02-02T14:57:48.925Z| vcpu-4| I120: CDROM ide1:0: CMD 0x4d (LOG SENSE) FAILED (key 0x5 asc 0x20 ascq 0)
A potential issue that has recently come to my attention is that you cannot have more than one ESXi guest per VMFS data store on the physical ESXi host. I can't tell from the information provided whether or not ESXi5-2 is located on the same data store as ESXi5-1, but if so, this could be the source of your trouble.
Hi Jim,
Thanks for the fast response.
Both nested ESXi VM's did reside on the same NFS DataStore. I migrate ESXi5-2 to another Datastore and tried the VMotion again but it still fails.
There's some communication issue occurring between vCenter and this host for some reason.
I'll have to do some more digging around in the logs, I could just simply destroy the ESXi VM and deploy a new one but I want to understand what's causing the issue.
Cheers
Scott
Being on the same NFS data store should be fine. It's only a problem if they are on the same VMFS data store (i.e. a local disk on the ESXi host).
A potential issue that has recently come to my attention is that you cannot have more than one ESXi guest per VMFS data store on the physical ESXi host.
What are the expected complications if you have more than one ESXi 5.1 guest on the same VMFS datastore where the ESXi 5.1 guests are running on an ESXi 5.1 physical host?
Also, is this an ESXi 5.1 only type of situation for ESXi 5.1physical hosts/ESXi 5.1 guests or are other versions of nested ESXi affected?
Thanks.
Datto
Datto schrieb:
A potential issue that has recently come to my attention is that you cannot have more than one ESXi guest per VMFS data store on the physical ESXi host.What are the expected complications if you have more than one ESXi 5.1 guest on the same VMFS datastore where the ESXi 5.1 guests are running on an ESXi 5.1 physical host?
Also, is this an ESXi 5.1 only type of situation for ESXi 5.1physical hosts/ESXi 5.1 guests or are other versions of nested ESXi affected?
Thanks.
Datto
Have you cloned the esxi virtual machines? Check if the vmkernel ports have different Mac addresses. I ran into such an issue before 🙂
Datto wrote:
What are the expected complications if you have more than one ESXi 5.1 guest on the same VMFS datastore where the ESXi 5.1 guests are running on an ESXi 5.1 physical host?
I may have misunderstood the constraints. There are some scenarios in which you can end up with VMFS meta-data corruption. This is one of the reasons that nested ESXi is not supported. Let me try to clarify what those scenarios are.