VMware Communities
bestard
Contributor
Contributor

VM stuck on the step "Stopping VMware Tools service in the virtual machine" for a very long time

Hi,

I have two VMs created on workstation pro 9 and then cloned to workstation pro 12,

they worked fine but vmware showed "vmware-tools out of date", so I updated vmware-tools as well.

However, I found when I reboot or power off the guest OS, the shutdown process always stuck on

the step "Stopping VMware Tools service in the virtual machine" for a very long time.

snapshot1.png

I checked the vmware.log and found something odd, but I have no idea how to solve it. Hope someone can help. Thanks.

Here is the information:

Host OS: Linux redhat 6.5

guest OS: Linux redhat 6.5

vmware.log:

2016-04-15T17:56:02.605+08:00| vcpu-5| I125: GuestRpc: Reinitializing Channel 1(toolbox-dnd)

2016-04-15T17:56:02.606+08:00| vcpu-6| I125: VMMouse: CMD Disable

2016-04-15T17:56:02.606+08:00| vcpu-6| I125: VMMouse: Disabling VMMouse mode

2016-04-15T17:56:04.176+08:00| svga| I125: SVGA-ScreenMgr: Screen type changed to RegisterMode

2016-04-15T17:56:04.347+08:00| vcpu-0| I125: Guest OS = 0x0

2016-04-15T17:56:04.469+08:00| svga| I125: SVGA disabling SVGA

2016-04-15T17:56:04.954+08:00| vmx| I125: SOCKET 4279 (181) recv detected client closed connection

2016-04-15T17:56:04.954+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4070.

2016-04-15T17:56:09.443+08:00| vmx| I125: SOCKET 4280 (181) recv detected client closed connection

2016-04-15T17:56:09.443+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4071.

2016-04-15T17:56:14.439+08:00| vmx| I125: SOCKET 4281 (181) recv detected client closed connection

2016-04-15T17:56:14.439+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4072.

2016-04-15T17:56:17.442+08:00| vmx| I125: TOOLS autoupgrade protocol version 0

2016-04-15T17:56:17.443+08:00| vmx| I125: GuestRpc: Got error for channel 0 connection 1952: Remote connection failure

2016-04-15T17:56:17.451+08:00| vcpu-0| I125: GuestRpc: Reinitializing Channel 0(toolbox)

2016-04-15T17:56:39.408+08:00| vcpu-0| I125: Tools: Tools heartbeat timeout.

2016-04-15T17:56:42.674+08:00| vmx| I125: SOCKET creating new socket, connecting to /var/run/vmware/usbarbitrator-socket

2016-04-15T17:56:42.674+08:00| vmx| I125: SOCKET connect failed, error 2: No such file or directory

2016-04-15T17:58:42.674+08:00| vmx| I125: SOCKET creating new socket, connecting to /var/run/vmware/usbarbitrator-socket

2016-04-15T17:58:42.674+08:00| vmx| I125: SOCKET connect failed, error 2: No such file or directory

2016-04-15T17:59:19.418+08:00| vmx| I125: GuestRpcSendTimedOut: message to toolbox timed out.

2016-04-15T17:59:19.418+08:00| vmx| I125: Vix: [71593 guestCommands.c:1937]: Error VIX_E_TOOLS_NOT_RUNNING in VMAutomationTranslateGuestRpcError(): VMware Tools are not running in the guest

2016-04-15T17:59:19.668+08:00| vmx| I125: SOCKET 4282 (181) recv detected client closed connection

2016-04-15T17:59:19.669+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4073.

2016-04-15T18:00:42.675+08:00| vmx| I125: SOCKET creating new socket, connecting to /var/run/vmware/usbarbitrator-socket

2016-04-15T18:00:42.675+08:00| vmx| I125: SOCKET connect failed, error 2: No such file or directory

2016-04-15T18:02:24.405+08:00| vmx| I125: GuestRpcSendTimedOut: message to toolbox timed out.

2016-04-15T18:02:24.405+08:00| vmx| I125: Vix: [71593 guestCommands.c:1937]: Error VIX_E_TOOLS_NOT_RUNNING in VMAutomationTranslateGuestRpcError(): VMware Tools are not running in the guest

2016-04-15T18:02:24.460+08:00| vmx| I125: SOCKET 4285 (181) recv detected client closed connection

2016-04-15T18:02:24.460+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4074.

2016-04-15T18:02:42.675+08:00| vmx| I125: SOCKET creating new socket, connecting to /var/run/vmware/usbarbitrator-socket

2016-04-15T18:02:42.675+08:00| vmx| I125: SOCKET connect failed, error 2: No such file or directory

2016-04-15T18:04:42.675+08:00| vmx| I125: SOCKET creating new socket, connecting to /var/run/vmware/usbarbitrator-socket

2016-04-15T18:04:42.675+08:00| vmx| I125: SOCKET connect failed, error 2: No such file or directory

2016-04-15T18:04:51.183+08:00| vcpu-0| I125: UHCI: HCReset

2016-04-15T18:04:51.185+08:00| vcpu-0| I125: CPU reset: soft (mode 1)

2016-04-15T18:04:51.185+08:00| vcpu-4| I125: CPU reset: soft (mode 1)

2016-04-15T18:04:51.186+08:00| vcpu-3| I125: CPU reset: soft (mode 1)

2016-04-15T18:04:51.186+08:00| vcpu-5| I125: CPU reset: soft (mode 1)

2016-04-15T18:04:51.186+08:00| vcpu-2| I125: CPU reset: soft (mode 1)

2016-04-15T18:04:51.186+08:00| vcpu-7| I125: CPU reset: soft (mode 1)

2016-04-15T18:04:51.186+08:00| vcpu-1| I125: CPU reset: soft (mode 1)

2016-04-15T18:04:51.186+08:00| vcpu-6| I125: CPU reset: soft (mode 1)

2016-04-15T18:04:51.188+08:00| vcpu-0| I125: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.188+08:00| vcpu-0| I125: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.188+08:00| vcpu-0| I125: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.188+08:00| vcpu-0| I125: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.189+08:00| vcpu-0| I125: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.189+08:00| vcpu-0| I125: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.189+08:00| vcpu-0| I125: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.189+08:00| vcpu-0| I125: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.189+08:00| vcpu-0| I125: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.189+08:00| vcpu-0| I125: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.189+08:00| vcpu-0| I125: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.189+08:00| vcpu-0| I125: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.190+08:00| vcpu-0| I125: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.190+08:00| vcpu-0| I125: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.190+08:00| vcpu-0| I125: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.190+08:00| vcpu-0| I125: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.190+08:00| vcpu-0| I125: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.190+08:00| vcpu-0| I125: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.190+08:00| vcpu-0| I125: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.190+08:00| vcpu-0| I125: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.190+08:00| vcpu-0| I125: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.191+08:00| vcpu-0| I125: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.191+08:00| vcpu-0| I125: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.191+08:00| vcpu-0| I125: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.191+08:00| vcpu-0| I125: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.191+08:00| vcpu-0| I125: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.191+08:00| vcpu-0| I125: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.191+08:00| vcpu-0| I125: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.191+08:00| vcpu-0| I125: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.192+08:00| vcpu-0| I125: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.192+08:00| vcpu-0| I125: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.192+08:00| vcpu-0| I125: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.248+08:00| vcpu-0| I125: CDROM: Reset guest state on 'ide1:0'. Invalidating last poll command time.

2016-04-15T18:04:51.376+08:00| vcpu-0| I125: SVGA: Unregistering IOSpace at 0x1070

2016-04-15T18:04:51.376+08:00| vcpu-0| I125: SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:51.394+08:00| vcpu-0| I125: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.395+08:00| vcpu-0| I125: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.395+08:00| vcpu-0| I125: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.396+08:00| vcpu-0| I125: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.396+08:00| vcpu-0| I125: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.397+08:00| vcpu-0| I125: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.397+08:00| vcpu-0| I125: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.398+08:00| vcpu-0| I125: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.399+08:00| vcpu-0| I125: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.399+08:00| vcpu-0| I125: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.400+08:00| vcpu-0| I125: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.400+08:00| vcpu-0| I125: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.401+08:00| vcpu-0| I125: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.401+08:00| vcpu-0| I125: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.402+08:00| vcpu-0| I125: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.403+08:00| vcpu-0| I125: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.403+08:00| vcpu-0| I125: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.404+08:00| vcpu-0| I125: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.404+08:00| vcpu-0| I125: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.405+08:00| vcpu-0| I125: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.405+08:00| vcpu-0| I125: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.406+08:00| vcpu-0| I125: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.407+08:00| vcpu-0| I125: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.407+08:00| vcpu-0| I125: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.408+08:00| vcpu-0| I125: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.408+08:00| vcpu-0| I125: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.409+08:00| vcpu-0| I125: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.409+08:00| vcpu-0| I125: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.410+08:00| vcpu-0| I125: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.411+08:00| vcpu-0| I125: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.411+08:00| vcpu-0| I125: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.412+08:00| vcpu-0| I125: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:51.414+08:00| vcpu-0| I125: UHCI: HCReset

2016-04-15T18:04:51.693+08:00| vcpu-0| I125: SVGA: Registering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:51.704+08:00| vcpu-0| I125: SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:51.973+08:00| vcpu-0| I125: SVGA: Registering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:51.986+08:00| vcpu-0| I125: SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:51.998+08:00| vcpu-0| I125: SVGA: Registering IOSpace at 0x1070

2016-04-15T18:04:51.998+08:00| vcpu-0| I125: SVGA: Registering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:52.006+08:00| vcpu-0| I125: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.007+08:00| vcpu-0| I125: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.009+08:00| vcpu-0| I125: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.010+08:00| vcpu-0| I125: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.012+08:00| vcpu-0| I125: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.013+08:00| vcpu-0| I125: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.015+08:00| vcpu-0| I125: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.016+08:00| vcpu-0| I125: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.018+08:00| vcpu-0| I125: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.019+08:00| vcpu-0| I125: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.021+08:00| vcpu-0| I125: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.023+08:00| vcpu-0| I125: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.025+08:00| vcpu-0| I125: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.026+08:00| vcpu-0| I125: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.028+08:00| vcpu-0| I125: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.029+08:00| vcpu-0| I125: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.031+08:00| vcpu-0| I125: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.032+08:00| vcpu-0| I125: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.034+08:00| vcpu-0| I125: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.035+08:00| vcpu-0| I125: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.037+08:00| vcpu-0| I125: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.038+08:00| vcpu-0| I125: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.040+08:00| vcpu-0| I125: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.041+08:00| vcpu-0| I125: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.043+08:00| vcpu-0| I125: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.044+08:00| vcpu-0| I125: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.046+08:00| vcpu-0| I125: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.047+08:00| vcpu-0| I125: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.049+08:00| vcpu-0| I125: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.050+08:00| vcpu-0| I125: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.052+08:00| vcpu-0| I125: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.054+08:00| vcpu-0| I125: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.057+08:00| vcpu-1| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:52.062+08:00| vcpu-2| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:52.067+08:00| vcpu-3| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:52.072+08:00| vcpu-4| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:52.077+08:00| vcpu-5| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:52.081+08:00| vcpu-6| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:52.086+08:00| vcpu-7| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:52.267+08:00| vcpu-0| I125: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.270+08:00| vcpu-0| I125: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.273+08:00| vcpu-0| I125: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.275+08:00| vcpu-0| I125: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.278+08:00| vcpu-0| I125: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.281+08:00| vcpu-0| I125: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.283+08:00| vcpu-0| I125: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.286+08:00| vcpu-0| I125: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.289+08:00| vcpu-0| I125: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.291+08:00| vcpu-0| I125: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.294+08:00| vcpu-0| I125: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.297+08:00| vcpu-0| I125: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.299+08:00| vcpu-0| I125: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.302+08:00| vcpu-0| I125: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.305+08:00| vcpu-0| I125: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.307+08:00| vcpu-0| I125: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.310+08:00| vcpu-0| I125: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.313+08:00| vcpu-0| I125: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.315+08:00| vcpu-0| I125: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.318+08:00| vcpu-0| I125: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.320+08:00| vcpu-0| I125: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.323+08:00| vcpu-0| I125: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.326+08:00| vcpu-0| I125: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.328+08:00| vcpu-0| I125: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.331+08:00| vcpu-0| I125: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.334+08:00| vcpu-0| I125: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.336+08:00| vcpu-0| I125: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.339+08:00| vcpu-0| I125: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.342+08:00| vcpu-0| I125: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.344+08:00| vcpu-0| I125: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.347+08:00| vcpu-0| I125: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.350+08:00| vcpu-0| I125: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:52.374+08:00| vcpu-0| I125: DISKUTIL: scsi0:0 : geometry=16709/255/63

2016-04-15T18:04:52.374+08:00| vcpu-0| I125: DISKUTIL: scsi0:0 : capacity=268435456 logical sector size=512

2016-04-15T18:04:52.374+08:00| vcpu-0| I125: SCSI0: RESET BUS

2016-04-15T18:04:53.210+08:00| vcpu-1| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:53.211+08:00| vcpu-2| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:53.212+08:00| vcpu-3| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:53.213+08:00| vcpu-4| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:53.214+08:00| vcpu-5| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:53.215+08:00| vcpu-6| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:53.216+08:00| vcpu-7| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:53.248+08:00| vcpu-0| I125: BIOS-UUID is 56 4d 26 16 97 d3 18 3a-2c 5f 55 83 79 92 80 b4

2016-04-15T18:04:58.492+08:00| vcpu-1| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:58.504+08:00| vcpu-2| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:58.517+08:00| vcpu-3| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:58.530+08:00| vcpu-4| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:58.542+08:00| vcpu-5| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:58.555+08:00| vcpu-6| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:58.568+08:00| vcpu-7| I125: CPU reset: soft (mode 2)

2016-04-15T18:04:59.091+08:00| vcpu-0| I125: SVGA: Unregistering IOSpace at 0x1070

2016-04-15T18:04:59.092+08:00| vcpu-0| I125: SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.105+08:00| vcpu-0| I125: SVGA: Registering IOSpace at 0x1070

2016-04-15T18:04:59.105+08:00| vcpu-0| I125: SVGA: Registering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.108+08:00| vcpu-0| I125: SVGA: Unregistering IOSpace at 0x1070

2016-04-15T18:04:59.108+08:00| vcpu-0| I125: SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.121+08:00| vcpu-0| I125: SVGA: Registering IOSpace at 0x1070

2016-04-15T18:04:59.121+08:00| vcpu-0| I125: SVGA: Registering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.126+08:00| vcpu-0| I125: SVGA: Unregistering IOSpace at 0x1070

2016-04-15T18:04:59.126+08:00| vcpu-0| I125: SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.139+08:00| vcpu-0| I125: SVGA: Registering IOSpace at 0x1070

2016-04-15T18:04:59.140+08:00| vcpu-0| I125: SVGA: Registering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.142+08:00| vcpu-0| I125: SVGA: Unregistering IOSpace at 0x1070

2016-04-15T18:04:59.142+08:00| vcpu-0| I125: SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.155+08:00| vcpu-0| I125: SVGA: Registering IOSpace at 0x1070

2016-04-15T18:04:59.155+08:00| vcpu-0| I125: SVGA: Registering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.158+08:00| vcpu-0| I125: SVGA: Unregistering IOSpace at 0x1070

2016-04-15T18:04:59.158+08:00| vcpu-0| I125: SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.171+08:00| vcpu-0| I125: SVGA: Registering IOSpace at 0x1070

2016-04-15T18:04:59.172+08:00| vcpu-0| I125: SVGA: Registering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.174+08:00| vcpu-0| I125: SVGA: Unregistering IOSpace at 0x1070

2016-04-15T18:04:59.174+08:00| vcpu-0| I125: SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.187+08:00| vcpu-0| I125: SVGA: Registering IOSpace at 0x1070

2016-04-15T18:04:59.188+08:00| vcpu-0| I125: SVGA: Registering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.190+08:00| vcpu-0| I125: SVGA: Unregistering IOSpace at 0x1070

2016-04-15T18:04:59.190+08:00| vcpu-0| I125: SVGA: Unregistering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.205+08:00| vcpu-0| I125: SVGA: Registering IOSpace at 0x1070

2016-04-15T18:04:59.205+08:00| vcpu-0| I125: SVGA: Registering MemSpace at 0xe8000000(0xe8000000) and 0xfe000000(0xfe000000)

2016-04-15T18:04:59.308+08:00| vcpu-0| I125: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.309+08:00| vcpu-0| I125: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.309+08:00| vcpu-0| I125: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.310+08:00| vcpu-0| I125: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.310+08:00| vcpu-0| I125: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.311+08:00| vcpu-0| I125: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.311+08:00| vcpu-0| I125: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.312+08:00| vcpu-0| I125: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.312+08:00| vcpu-0| I125: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.313+08:00| vcpu-0| I125: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.313+08:00| vcpu-0| I125: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.314+08:00| vcpu-0| I125: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.314+08:00| vcpu-0| I125: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.315+08:00| vcpu-0| I125: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.315+08:00| vcpu-0| I125: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.316+08:00| vcpu-0| I125: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.316+08:00| vcpu-0| I125: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.317+08:00| vcpu-0| I125: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.317+08:00| vcpu-0| I125: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.317+08:00| vcpu-0| I125: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.317+08:00| vcpu-0| I125: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.318+08:00| vcpu-0| I125: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.318+08:00| vcpu-0| I125: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.319+08:00| vcpu-0| I125: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.319+08:00| vcpu-0| I125: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.320+08:00| vcpu-0| I125: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.320+08:00| vcpu-0| I125: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.321+08:00| vcpu-0| I125: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.321+08:00| vcpu-0| I125: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.322+08:00| vcpu-0| I125: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.322+08:00| vcpu-0| I125: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.323+08:00| vcpu-0| I125: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.323+08:00| vcpu-0| I125: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.324+08:00| vcpu-0| I125: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.324+08:00| vcpu-0| I125: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.325+08:00| vcpu-0| I125: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.325+08:00| vcpu-0| I125: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.325+08:00| vcpu-0| I125: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.325+08:00| vcpu-0| I125: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.326+08:00| vcpu-0| I125: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.326+08:00| vcpu-0| I125: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.327+08:00| vcpu-0| I125: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.327+08:00| vcpu-0| I125: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.328+08:00| vcpu-0| I125: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.328+08:00| vcpu-0| I125: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.329+08:00| vcpu-0| I125: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.329+08:00| vcpu-0| I125: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.330+08:00| vcpu-0| I125: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.330+08:00| vcpu-0| I125: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.331+08:00| vcpu-0| I125: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.331+08:00| vcpu-0| I125: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.332+08:00| vcpu-0| I125: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.332+08:00| vcpu-0| I125: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.332+08:00| vcpu-0| I125: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.333+08:00| vcpu-0| I125: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.333+08:00| vcpu-0| I125: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.333+08:00| vcpu-0| I125: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.334+08:00| vcpu-0| I125: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.334+08:00| vcpu-0| I125: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.335+08:00| vcpu-0| I125: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.335+08:00| vcpu-0| I125: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.336+08:00| vcpu-0| I125: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.336+08:00| vcpu-0| I125: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.337+08:00| vcpu-0| I125: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.337+08:00| vcpu-0| I125: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.337+08:00| vcpu-0| I125: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.337+08:00| vcpu-0| I125: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.337+08:00| vcpu-0| I125: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.337+08:00| vcpu-0| I125: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.337+08:00| vcpu-0| I125: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.337+08:00| vcpu-0| I125: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.337+08:00| vcpu-0| I125: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.338+08:00| vcpu-0| I125: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.339+08:00| vcpu-0| I125: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.340+08:00| vcpu-0| I125: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.681+08:00| vcpu-0| I125: PCIBridge4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.682+08:00| vcpu-0| I125: pciBridge4:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.682+08:00| vcpu-0| I125: pciBridge4:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.682+08:00| vcpu-0| I125: pciBridge4:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.682+08:00| vcpu-0| I125: pciBridge4:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.682+08:00| vcpu-0| I125: pciBridge4:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.683+08:00| vcpu-0| I125: pciBridge4:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.683+08:00| vcpu-0| I125: pciBridge4:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.683+08:00| vcpu-0| I125: PCIBridge5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.683+08:00| vcpu-0| I125: pciBridge5:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.683+08:00| vcpu-0| I125: pciBridge5:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.684+08:00| vcpu-0| I125: pciBridge5:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.684+08:00| vcpu-0| I125: pciBridge5:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.684+08:00| vcpu-0| I125: pciBridge5:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.684+08:00| vcpu-0| I125: pciBridge5:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.685+08:00| vcpu-0| I125: pciBridge5:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.685+08:00| vcpu-0| I125: PCIBridge6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.685+08:00| vcpu-0| I125: pciBridge6:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.685+08:00| vcpu-0| I125: pciBridge6:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.685+08:00| vcpu-0| I125: pciBridge6:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.686+08:00| vcpu-0| I125: pciBridge6:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.686+08:00| vcpu-0| I125: pciBridge6:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.686+08:00| vcpu-0| I125: pciBridge6:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.686+08:00| vcpu-0| I125: pciBridge6:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.686+08:00| vcpu-0| I125: PCIBridge7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.687+08:00| vcpu-0| I125: pciBridge7:1: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.687+08:00| vcpu-0| I125: pciBridge7:2: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.687+08:00| vcpu-0| I125: pciBridge7:3: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.687+08:00| vcpu-0| I125: pciBridge7:4: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.687+08:00| vcpu-0| I125: pciBridge7:5: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.688+08:00| vcpu-0| I125: pciBridge7:6: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.688+08:00| vcpu-0| I125: pciBridge7:7: ISA/VGA decoding enabled (ctrl 0004)

2016-04-15T18:04:59.708+08:00| vcpu-0| I125: UHCI: HCReset

2016-04-15T18:05:01.882+08:00| vcpu-1| I125: UHCI: HCReset

2016-04-15T18:05:02.398+08:00| vcpu-4| I125: SCSI0: RESET BUS

2016-04-15T18:05:02.485+08:00| vcpu-4| I125: SCSI0: RESET BUS

2016-04-15T18:05:02.659+08:00| vcpu-5| I125: DISKUTIL: scsi0:0 : capacity=268435456 logical sector size=512

2016-04-15T18:05:02.659+08:00| vcpu-0| I125: SCSI DEVICE (scsi0:0): MODE SENSE(6) for unsupported page 0x8

2016-04-15T18:05:02.660+08:00| vcpu-0| I125: DISKUTIL: scsi0:0 : capacity=268435456 logical sector size=512

2016-04-15T18:05:02.660+08:00| vcpu-0| I125: SCSI DEVICE (scsi0:0): MODE SENSE(6) for unsupported page 0x8

2016-04-15T18:05:02.661+08:00| vcpu-0| I125: DISKUTIL: scsi0:0 : capacity=268435456 logical sector size=512

2016-04-15T18:05:02.661+08:00| vcpu-0| I125: SCSI DEVICE (scsi0:0): MODE SENSE(6) for unsupported page 0x8

2016-04-15T18:05:02.669+08:00| vcpu-0| I125: CDROM: Emulate GET CONFIGURATION RT 0 starting feature 0

2016-04-15T18:05:02.669+08:00| vcpu-0| I125: CDROM: Emulate GET CONFIGURATION RT 0 starting feature 0

2016-04-15T18:05:06.059+08:00| vcpu-5| I125: CDROM: Emulate GET CONFIGURATION RT 0 starting feature 0

2016-04-15T18:05:06.059+08:00| vcpu-5| I125: CDROM: Emulate GET CONFIGURATION RT 0 starting feature 0

2016-04-15T18:05:06.100+08:00| vcpu-0| W115: Balloon: Start: vmmemctl reset balloon

2016-04-15T18:05:06.100+08:00| vcpu-0| I125: Balloon: Reset (n 4 pages 0)

2016-04-15T18:05:06.100+08:00| vcpu-0| I125: Balloon: Reset: nUnlocked 0 size 0

2016-04-15T18:05:12.737+08:00| vmx| I125: Guest: toolbox: Version: build-3228253

2016-04-15T18:05:12.737+08:00| vcpu-0| W115: GuestRpc: application toolbox, changing channel 65535 -> 0

2016-04-15T18:05:12.737+08:00| vcpu-0| I125: GuestRpc: Channel 0, guest application toolbox.

2016-04-15T18:05:12.768+08:00| vmx| I125: TOOLS soft reset detected.

2016-04-15T18:05:12.769+08:00| vmx| I125: TOOLS autoupgrade protocol version 2

2016-04-15T18:05:12.770+08:00| vmx| I125: Vix: [71593 mainDispatch.c:4155]: VMAutomationReportPowerStateChange: Reporting power state change (opcode=2, err=0).

2016-04-15T18:05:12.771+08:00| vmx| I125: TOOLS Received tools.set.versiontype rpc call, version = 10245, type = 2

2016-04-15T18:05:12.771+08:00| vmx| I125: Tools_SetVersionAndType did nothing; new tools version (10245) and type (2) match old Tools version and type

2016-04-15T18:05:12.771+08:00| vmx| I125: TOOLS Setting autoupgrade-checked FALSE.

2016-04-15T18:05:12.771+08:00| vmx| I125: Starting copy guest manifest.

2016-04-15T18:05:12.779+08:00| vmx| I125: SOCKET 4287 (181) recv detected client closed connection

2016-04-15T18:05:12.779+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4075.

2016-04-15T18:05:14.431+08:00| vmx| I125: SOCKET 4291 (181) recv detected client closed connection

2016-04-15T18:05:14.431+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4076.

2016-04-15T18:05:17.128+08:00| vcpu-2| I125: CDROM: Emulate GET CONFIGURATION RT 2 starting feature 0

2016-04-15T18:05:17.128+08:00| vcpu-2| I125: CDROM: Emulate GET CONFIGURATION RT 2 starting feature 0

2016-04-15T18:05:17.143+08:00| vcpu-2| I125: VMMouse: CMD Read ID

2016-04-15T18:05:17.143+08:00| vcpu-2| I125: VMMouse: CMD Disable

2016-04-15T18:05:17.143+08:00| vcpu-2| I125: VMMouse: Disabling VMMouse mode

2016-04-15T18:05:19.403+08:00| vmx| I125: SOCKET 4292 (181) recv detected client closed connection

2016-04-15T18:05:19.403+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4077.

2016-04-15T18:05:23.173+08:00| svga| I125: SVGA enabling SVGA

2016-04-15T18:05:23.209+08:00| vcpu-4| I125: Guest OS = 0x5008

2016-04-15T18:05:23.211+08:00| svga| I125: Guest display topology changed: numDisplays 1

2016-04-15T18:05:23.219+08:00| svga| I125: SVGA-ScreenMgr: Screen type changed to TopologyMode

2016-04-15T18:05:23.405+08:00| vcpu-4| I125: VMMouse: CMD Read ID

2016-04-15T18:05:23.406+08:00| vcpu-4| I125: VMMouse: CMD Disable

2016-04-15T18:05:23.406+08:00| vcpu-4| I125: VMMouse: Disabling VMMouse mode

2016-04-15T18:05:23.437+08:00| vcpu-4| I125: VMMouse: CMD Read ID

2016-04-15T18:05:24.425+08:00| vmx| I125: SOCKET 4293 (181) recv detected client closed connection

2016-04-15T18:05:24.425+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4078.

2016-04-15T18:05:29.391+08:00| vmx| I125: SOCKET 4294 (181) recv detected client closed connection

2016-04-15T18:05:29.392+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4079.

2016-04-15T18:05:34.462+08:00| vmx| I125: SOCKET 4295 (181) recv detected client closed connection

2016-04-15T18:05:34.462+08:00| vmx| I125: Vix: [71593 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 4080.

Tags (1)
10 Replies
bestard
Contributor
Contributor

nobody can help ? Smiley Sad

I updated recent status as below.

It seems like there are some issues migrating VMs from a PC host to a Linux host.

My original guest image was created on workstation pro 9 and it is a linux red hat 6.5 guest running on windows 7 host.

Then I cloned the VM to a linux host who runs workstation pro 12 on the red hat 6.5 Linux OS as well.

I reinstalled the new version vmware-tools inside the guest and change settings, it can run well on the host,

but it showed those messages as I posted above when I reboot or shutdown the guest though.

So this time I decided to reinstall the guest OS instead of cloning the image to see if I can clear some issues between different

workstation versions.

However, it looked like made no difference after I installed vmware-tools.

When I reboot/shutdown the guest, the whole process still hung in the step "VM communication interface socket family"

for a long time (around 6 minutes).

Please see the attached files. Hope someone can help me out.

Thanks.

0 Kudos
bestard
Contributor
Contributor

I'm really frustrated searching answers for this.

Today, I tried to remove the newest version of the vmware-tools 10.0.5-3228253 and install the old version 10.0.0-50046,

the guest didn't hang in the reboot/shutdown process and run quickly, but the following messages still kept showing up though

which were very annoying.

2016-04-20T12:11:46.025+08:00| vmx| I125: SOCKET 1306 (182) recv detected client closed connection

2016-04-20T12:11:46.025+08:00| vmx| I125: Vix: [82308 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 1271.

2016-04-20T12:11:51.043+08:00| vmx| I125: SOCKET 1307 (182) recv detected client closed connection

2016-04-20T12:11:51.043+08:00| vmx| I125: Vix: [82308 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 1272.

But that's the way it is, there is nothing more I can do if nobody can helps me. Smiley Sad

0 Kudos
wila
Immortal
Immortal

Hello Roger,

Welcome at the VMware community forums.

Don't be frustrated.. you actually did very well resolving this.

Please be aware that this is not an official support channel from VMware, it is a forum where users help other users.

This means that help is limited on free time being available.

Actually I did look at your problem earlier on, but did not have an answer and I was limited by my own time to research it there was not much I could do, so instead of answering "I have no answer for you" I did not reply as that reply isn't helpful at all.

There's a thing you should know about the log files and that is that not all "error messages" are errors. It takes some excercise to learn the differences. The error you are focusing on now is "informational", you can know that by looking at the row, behind "vmx| " it has the letter "I" from ... informational.

If you only see these lines in the log then that's fine.

The delay problem you saw started at:

2016-04-15T17:56:39.408+08:00| vcpu-0| I125: Tools: Tools heartbeat timeout.

until:

2016-04-15T18:04:42.675+08:00| vmx| I125: SOCKET connect failed, error 2: No such file or directory

That's where the 7 minutes  delay went.

The main reason being a VMware Tools installation not having installed completely correctly for some reason.

As you reinstalled an older version of VMware Tools that seems to have resolved. It is possible that it is still fixed if you install the newer version again, but I don't know.

For the moment I would just let it be if I were you. Unless you have a specific problem with the guest OS I wouldn't worry too much.

Hope this helps,

--

Wil

| Author of Vimalin. The virtual machine Backup app for VMware Fusion, VMware Workstation and Player |
| More info at vimalin.com | Twitter @wilva
0 Kudos
bestard
Contributor
Contributor

Hello Wila,

Thank you for your response that I know at least someone were aware of my problem.

I've been searching answers and trying anything I can to resolve the problems for two days, but it was not as I expected.

There are two questions I am concerned.

1. The delay issue.

2. The "VMAutomation connection error" messages kept showing up which are very annoying. I want to know what made it occurred.

2016-04-20T11:41:29.496+08:00| vmx| I125: SOCKET 47 (182) recv detected client closed connection

2016-04-20T11:41:29.496+08:00| vmx| I125: Vix: [89376 mainDispatch.c:2826]: VMAutomation: Connection Error (4) on connection 35.

As for the first, I did trying reinstall the newer version couple times, I'm sure the installation process was completed,

but that didn't work. That's why I downgrade the vmware-tools to the old version.

If something has to be mentioned, there were some messages shown during the installation,

The messages are as below,

Found a compatible pre-built module for vmci.  Installing it...

Found a compatible pre-built module for vsock.  Installing it...

The module vmxnet3 has already been installed on this system by another

installer or package and will not be modified by this installer.

The module pvscsi has already been installed on this system by another

installer or package and will not be modified by this installer.

The module vmmemctl has already been installed on this system by another

installer or package and will not be modified by this installer.

but they were the same messages showed up during installing the old version, does that matters?

As for the second, It still bothers me. I have no idea how to make it disappear.

Thank you.

0 Kudos
wila
Immortal
Immortal

Hi,

It's unfortunately not always clear why those error messages are in the log.

There can be reasons like:

- firewalling

- as you are using Red Hat Linux it might also be SELinux not playing along

- The end point (eg. vmware tools in the guest) might not be installed correctly, or one of the libraries it depends on is different from what it expects.

- The connect point (eg. vmware support at the host) might not be installed correctly or one of the libraries "" "" ""

Usually when you are using a recent Linux guest, it is suggested to use open-vm-tools.

I wouldn't call RH 6.5 exactly recent, but you can still have open-vm-tools installed which could explain the messages that mention "has been installed on this system by another installer or package"

Note that some versions of open-vm-tools have issues with shared folders, so if you depend on that feature, open-vm-tools might not suffice.

re your 2nd problem.

If it is only in the log then there is nothing to worry about.

Are you also seeing these errors in the application itself on starting up the guest?

--

Wil

| Author of Vimalin. The virtual machine Backup app for VMware Fusion, VMware Workstation and Player |
| More info at vimalin.com | Twitter @wilva
bestard
Contributor
Contributor

Hello Wila,

Thank you for your suggestion.

- firewalling

- as you are using Red Hat Linux it might also be SELinux not playing along

- The end point (eg. vmware tools in the guest) might not be installed correctly, or one of the libraries it depends on is different from what it expects.

- The connect point (eg. vmware support at the host) might not be installed correctly or one of the libraries "" "" ""

As for you said, I didn't activate SELinux. According to Knowledge Base 1033693. It seems like there exists some issues between vmware-tools and SELinux.

May I ask how do I know if the open-vm-tools has been installed in the guest?

It was a pure clean installed guest, I didn't install any application yet unless open-vm-tools is an embedded service inside the red hat installation disc.

As for the 2nd problem, those messages were just only in the log but they kept showing up in the log,

so I think there must be something odd needed to be clarified.

I don't see errors in the application itself on starting up the guest....well, as for now, I'm not so sure, but I'll keep monitoring.

--

Regards,

Roger

0 Kudos
wila
Immortal
Immortal

Hi Roger,

The KB article also mentions that Red Hat has resolved the issue in a later update. So if you are up-to-date then SELinux should not have an issue.

Anyways as you've not enabled SELinux, it is not a factor.

re. how-to see if open-vm-tools is installed?

# yum list | grep open-vm-tools

I now start to wonder if I was wrong and the kernel modules are just there from earlier installs of vmware-tools and had not been removed.

Anyways.. if the only problem you have is the message showing up in the vmware.log then there's no issue as there's lots of informational "errors" in there.

Vix is used to make it possible to communicate with the Virtual Machine from the host, you can access most of its functions via the vmrun interface.

See VMware Workstation Pro Documentation for details on that.

My bet is that that just works and that you're fine.

It would have been a problem if there was a mention of these items when starting the VM within the normal VMware user interface.

--

Wil

| Author of Vimalin. The virtual machine Backup app for VMware Fusion, VMware Workstation and Player |
| More info at vimalin.com | Twitter @wilva
bestard
Contributor
Contributor

Hello Wila,

# yum list | grep open-vm-tools

As for the command you suggested,  the result is as below,

I don't see anything related to open-vm-tools,

# yum list | grep vm

libXxf86vm.x86_64                        1.1.2-2.el6                           @anaconda-RedHatEnterpriseLinux-201311111358.x86_64/6.5

lvm2.x86_64                              2.02.100-8.el6                        @anaconda-RedHatEnterpriseLinux-201311111358.x86_64/6.5

lvm2-libs.x86_64                         2.02.100-8.el6                        @anaconda-RedHatEnterpriseLinux-201311111358.x86_64/6.5

mesa-private-llvm.x86_64                 3.3-0.3.rc3.el6                       @anaconda-RedHatEnterpriseLinux-201311111358.x86_64/6.5

xorg-x11-drv-vmmouse.x86_64              12.9.0-10.el6                         @anaconda-RedHatEnterpriseLinux-201311111358.x86_64/6.5

xorg-x11-drv-vmware.x86_64               12.0.2-3.20120718gite5ac80d8f.el6     @anaconda-RedHatEnterpriseLinux-201311111358.x86_64/6.5

Anyway, thanks for your suggestion. I'll spend some time studying vmware documents if I do have the time. lol

I'm kind of hesitate closing this case, I want to see if anyone knows anything about my issues.

--

Regards,

Roger

0 Kudos
wila
Immortal
Immortal

Hello Roger,

It's not a support case, there's no "close" button.

For the record, you can of course open a support case for this, but it will cost money unless you are still within -I think- 30 days of buying VMware Workstation.

The forum allows you to assign points to people that help and while I appreciate that, I'm perfectly happy without that as well as I'm not helping out to gather points.

Either way, people can reply with more info at any time later on.

--

Wil

| Author of Vimalin. The virtual machine Backup app for VMware Fusion, VMware Workstation and Player |
| More info at vimalin.com | Twitter @wilva
0 Kudos
bestard
Contributor
Contributor

Hello Wila,

It seems like I use some "improper" words here.:smileysilly:

Anyway, thank you for your mention.

--

Regards,

Roger

0 Kudos