Vsphere Host connection and power state

maumercado

Hello all,

Ive been having a problem with vcenter server, it randomly disconnects from the host esxi 4, connection does not last more than 5 minutes, Ive been trying to figure out what this is... and so far I got nothing, I found this:

[2010-01-25 12:24:55.062 06976 info 'App'] [VpxdMoHost::DisconnectInt] Marked 10
.125.30.6 as dirty.

warning 'Libs'] SSLVerifyCertAgainstSystemStore: The remote host certificate has these problems: The host certificate chain is not complete.

When I saw that last error in the logs I disabled the vcenter requires check SSL in the advanced ssl settings, but still got disconnected.

My version of vsphere client is 4.0.0 and vcenter server is 4.0.0... the server and its virtual machines keep on working but I cant manage the esxi host.

Ill appreciate the help...

maumercado

Update...

I remove and added the host again and did not work... im starting to get frustrated!

dales

The VM's stay up I take it (oops read the post) ,how do you connect to vcenter ip/dns and also how did you connect the esxi box to vcenter was that ip or dns?

I think I have seen this before and it boiled down to some kinda dns issue but I cant quite remember

maumercado

The vcenter server and the databases are in the same computer in which I have the vcenter client. I connect by dns to it...

astorrs

Is the vCenter server multihomed? Is there any NAT between the hosts and vCenter (like in a DMZ)?

maumercado

The vcenter is not multihomed and theres no NAT between the vcenter and the hosts, there is some packet tagging involve since the host is in a different vlan from the vcenter, but no ACL is configured in the switch that does the tagging...

astorrs

Okay good, had to ask as that's a common issue with DMZ's/security paranoid IT depts/etc.

Can you log into unsupported mode on the ESXi host experiencing the problems and check the vmware/vpx/vpxa.log logfile to see what's happening to vCenter communications? Send me a PM if you want help diagnosing the contents.

maumercado

Checking the logs and ... could anyone help me out interpreting this:

[2010-01-26 09:49:57.776 0x13366b90 verbose 'App'] Setting the management server IP to 10.125.30.6
[2010-01-26 09:49:57.777 0x135a6b90 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
[2010-01-26 09:49:57.777 0x135a6b90 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 16561 to 16562 (at 16561)
[2010-01-26 09:49:57.777 0x13366b90 verbose 'App'] [VpxaInvtHost] Syncing the firmware configuration.
[2010-01-26 09:49:57.779 0x13366b90 error 'App'] [VpxaInvtHost] Error syncing firmware configuration: vim.fault.TooManyWrites
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] [VpxaInvtHost] Increment master gen. no to (9449): configStatus:vpxa issue posted
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] [VpxaInvtHost] Increment master gen. no to (9450): Event:vpxa issue posted
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] [VpxaInvtHost] Increment master gen. no to (9451): configStatus:vpxa issue removed
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] [VpxaVmomi] Disconnect 127.0.0.1
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] CloseSession called for session id=5230cb04-d93f-4232-0537-a93ef6f6c35a
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] [VpxaVmomi] Disconnect 127.0.0.1
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] CloseSession called for session id=527f8ba3-c338-340c-8c67-d740bd917aaa
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] [VpxaVmomi] Disconnect 127.0.0.1
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] CloseSession called for session id=52c6836d-f9e0-ca7a-f95c-294a9cb326cf
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] [VpxaVmomi] Disconnect 127.0.0.1
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] CloseSession called for session id=52d2ccc7-5543-3e10-9b46-3e72350b189b
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] [VpxaVmomi] Disconnect 127.0.0.1
[2010-01-26 09:49:57.779 0x13366b90 verbose 'App'] CloseSession called for session id=52dc21b9-9b85-6afb-eefe-b06ddf0401ff
[2010-01-26 09:49:57.787 0x13669b90 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
[2010-01-26 09:49:57.787 0x13366b90 info 'App'] [VpxaHalHostHostagent::SetManagementNic]Setting the NIC with address 10.125.30.6 as a management nic
[2010-01-26 09:49:57.787 0x13669b90 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 16562 to 16563 (at 16562)
[2010-01-26 09:49:57.787 0x13669b90 verbose 'App'] [VpxaHalServices] HostChanged Event Fired, properties changed [summary.managementServerIp]
[2010-01-26 09:49:57.787 0x13669b90 verbose 'App'] [VpxaInvtHost] Increment master gen. no to (9452): HostConfig:VpxaInvtHostListener::HostChanged(summary.managementServerIp)
[2010-01-26 09:49:57.790 0x13366b90 verbose 'SoapAdapter.HTTPService'] HTTP Response: Complete (processed 384 bytes)
[2010-01-26 09:49:57.791 0x13366b90 info 'App'] [VpxLRO] -- FINISH task-internal-429 -- -- vpxapi.VpxaService.setServer -- 5242d807-bb47-fb46-17e3-920f538d149e

[2010-01-26 09:50:36.131 0x131fbb90 verbose 'App'] [VpxaHalVmHostagent] 64: guestHeartbeatStatus changed to yellow
[2010-01-26 09:50:36.131 0x131fbb90 verbose 'App'] [VpxaHalServices] VmHeartbeatChange Event for vm(5) 64
[2010-01-26 09:50:36.131 0x131fbb90 verbose 'App'] [VpxaInvtVmChangeListener] Guest HeartbeatStatus Changed
[2010-01-26 09:50:42.542 0x13669b90 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
[2010-01-26 09:50:42.542 0x13669b90 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 16573 to 16574 (at 16573)
[2010-01-26 09:50:42.542 0x13669b90 verbose 'App'] [VpxaHalVmHostagent] 48: GuestInfo changed 'guest.disk'
[2010-01-26 09:50:42.542 0x13669b90 verbose 'App'] [VpxaHalServices] VmGuestDiskChange Event for vm(4) 48
[2010-01-26 09:50:42.542 0x13669b90 verbose 'App'] [VpxaInvtVmChangeListener] Guest DiskInfo Changed
[2010-01-26 09:50:42.868 0x135e7b90 warning 'App'] [VpxaHalStats] Unexpected return result. Expect 1 sample, receive 2
[2010-01-26 09:50:42.868 0x135e7b90 verbose 'App'] [QuickStats] Host CounterId 262165 has no value
[2010-01-26 09:50:42.868 0x135e7b90 verbose 'App'] [QuickStats] Host CounterId 262165 has no value
[2010-01-26 09:50:42.868 0x135e7b90 verbose 'App'] [QuickStats] Host CounterId 262165 has no value
[2010-01-26 09:50:42.868 0x135e7b90 verbose 'App'] [QuickStats] Host CounterId 262168 has no value
[2010-01-26 09:50:42.868 0x135e7b90 verbose 'App'] [QuickStats] Host CounterId 262168 has no value
[2010-01-26 09:50:44.221 0x131fbb90 verbose 'SoapAdapter.HTTPService'] User agent is 'VMware-client/4.0.0'
[2010-01-26 09:50:44.221 0x131fbb90 verbose 'SoapAdapter.HTTPService'] HTTP Response: Client: NeedsContentLength: false UnderstandsChunking: true CanKeepAlive: true (PresetContentLength -1)
[2010-01-26 09:50:44.221 0x13366b90 info 'App'] [VpxLRO] -- BEGIN task-internal-432 -- -- vpxapi.VpxaService.setServer -- 5242d807-bb47-fb46-17e3-920f538d149e
[2010-01-26 09:50:44.221 0x13366b90 info 'App'] [VpxaInvtHost] Server IP has been cleared by 10.125.30.6
[2010-01-26 09:50:44.225 0x13366b90 verbose 'App'] UnSetting the management server IP
[2010-01-26 09:50:44.227 0x13628b90 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
[2010-01-26 09:50:44.227 0x13628b90 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 16574 to 16575 (at 16574)
[2010-01-26 09:50:44.239 0x13366b90 verbose 'App'] [TaskInfoListener] Waiting on channel haTask-ha-compute-res-vim.ComputeResource.reconfigureEx-233698602
[2010-01-26 09:50:44.761 0x135e7b90 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
[2010-01-26 09:50:44.761 0x135e7b90 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 16575 to 16576 (at 16575)
[2010-01-26 09:50:44.763 0x135e7b90 verbose 'App'] [VpxaHalServices] HostChanged Event Fired, properties changed [summary.managementServerIp]
[2010-01-26 09:50:44.763 0x135e7b90 verbose 'App'] [VpxaInvtHost] Increment master gen. no to (9457): HostConfig:VpxaInvtHostListener::HostChanged(summary.managementServerIp)
[2010-01-26 09:50:44.765 0x136aab90 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
[2010-01-26 09:50:44.765 0x136aab90 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 16576 to 16577 (at 16576)
[2010-01-26 09:50:44.782 0x13366b90 info 'App'] [VpxaHalHostHostagent::SetManagementNic]Setting the NIC with address 10.125.30.6 as a management nic
[2010-01-26 09:50:44.785 0x1e266ab0 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
[2010-01-26 09:50:44.785 0x1e266ab0 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 16577 to 16578 (at 16577)

[2010-01-26 09:50:53.442 0x135a6b90 error 'PropertyCache'] Failed to diff 16:resourcePool, had ManagedObjectReference, got ManagedObjectReference

thats a piece of the vpxa.log

this one below apparently points the problem to my vcenter server:

[viclient:SoapTran] 2010-01-26 09:51:56.106 Invoke 275 Finish RetrieveContents on PropertyCollector:propertyCollector [vcenterserver] - Serial:0.000, Server:000.518
[viclient:SoapTran] 2010-01-26 09:52:16.099 Invoke 276 Start RetrieveContents on PropertyCollector:propertyCollector [vcenterserver]. [Caller: VpxClient.Common.PropertyPoller_PCImpl.RetrieveData]
[viclient:SoapTran] 2010-01-26 09:52:16.617 Invoke 276 Finish RetrieveContents on PropertyCollector:propertyCollector [vcenterserver] - Serial:0.000, Server:000.516
[Update M:SoapTran] 2010-01-26 09:52:17.620 Invoke 32 Finish WaitForUpdates on PropertyCollector:Integrity.PropertyCollector [vcenterserver:8084] - Serial:0.000, Server:299.998
Suppressed: VirtualInfrastructure.Soap.MethodInvocationSoapImpl: The request failed because the remote server 'vcenterserver' took too long to respond. (The command has timed out as the remote server is taking too long to respond.)
[Update M:Error ] 2010-01-26 09:52:17.621 ConnectionError occurred while executing WFU
VirtualInfrastructure.Exceptions.RequestTimedOut: The request failed because the remote server 'vcenterserver' took too long to respond. (The command has timed out as the remote server is taking too long to respond.)
en VirtualInfrastructure.Soap.SoapServiceWrapper.DoInvokeSync(ManagedObject mo, MethodName methodName, Object[] parameters, Int32 timeoutSecs)
en VirtualInfrastructure.Soap.SoapTransport.VirtualInfrastructure.Transport.InvokeMethod(ManagedObject mo, MethodName methodName, Object[] pars)
en VirtualInfrastructure.ManagedObject.InvokeMethod(MethodName methodName, Object[] pars)
en Vmomi.Core.PropertyCollector.WaitForUpdates(String version)
en VirtualInfrastructure.Updates.PollerDispatcherImpl.ExecuteSingleWFU()
en VirtualInfrastructure.Updates.PollerDispatcherImpl.PollWaitForUpdates()
System.Net.WebException: The command has timed out as the remote server is taking too long to respond.

maumercado

I probably have to say that I have Vcenter Server, vclient, update manager, veeam backup solution and veeam monitor in the same PC.

maumercado

FIXED... after a review of the esxi logs, and a review of the Vcenter Server logged I noticed this:

The request failed because the remote server 'vcenterserver' took too long to respond

which made me think it was a network problem of course... but what... so I isolated the problem with this --> VMware KB: Diagnosing an ESX Server that is Disconnected or Not Responding in VirtualCenter
and fixed it with this --> VMware KB: ESX host continually disconnects from the vCenter Server following an upgrade to ESX 4.0

Somehow the vCenter Server Managed IP was not pointing to where it was supposed to... I dont even remember having changed it... it was working fine since friday night... and now its working again...

Thanks everyone... hope this post is usefull to someone with the same issue...

astorrs

Glad you figured it out.

That's why I asked if it was NAT'd or multihomed, usually you would leave the vCenter Server Managed IP field empty unless one of those were true (or something else was preventing the ESX hosts from getting the correct IP address for the vCenter server).