Solved: "User root@127.0.0.1 logged in" every minute ?

TonyJK · ‎08-12-2012

Hi,

We observe that 2 ESXi 5 Hosts in the same cluster (We only have 2 ESXi Hosts in that Cluster) get the following message every minute:

User root@127.0.0.1 logged in

User root logged out

Both ESXi Host and vCenter Server are of the latest build. We also don't get such message in other Clusters of ESXi 5 Hosts.

That 2 ESXi Hosts are running on IBM Server with the latest IBM CIM installed.

Your advice is sought.

Thanks

CRad14 · ‎05-03-2013

This was my experience with IBM Hosts

http://www.vnoob.com/2013/04/constant-root-logins-to-ibm-esxi-hosts/

Conrad www.vnoob.com | @vNoob | If I or anyone else is helpful to you make sure you mark their posts as such! 🙂

View solution in original post

a_p_ · ‎08-12-2012

Only a thought. Are these two hosts configured differently from the others (e.g. do the other hosts also have the CIM providers installed) or do you use any third party applications (e.g. replication)?

see also http://kb.vmware.com/kb/1031578

André

TonyJK · ‎08-12-2012

We have a Veeam Backup and Replication VM on one of them. Would it be a cause ?

Is there any suggestion on checking what is the cause OR can we ignore it ?

Thanks

sa2057 · ‎08-13-2012

Hi,

Did you schedule any backup / replication jobs ?.. Say continuous replication

Thanks

SA

TonyJK · ‎08-13-2012

No.

Is there any way (Like Log File) to see what is running at the background ?

Thanks

sa2057 · ‎08-14-2012

Hi,

To view log file

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

Thanks

SA

sa2057 · ‎08-14-2012

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

have a look at this KB

Thanks

SA

TonyJK · ‎08-14-2012

Which log file contains the information I am after ? Is it the /var/log/vmkernel.log ?

Thanks again

sa2057 · ‎08-15-2012

Hi,

Do you have any monitoring/managements agents installed on the Hosts?..

Thanks

SA

sa2057 · ‎08-15-2012

Check this thread.. Might help you..

http://communities.vmware.com/thread/76377

Thanks

SA

TonyJK · ‎08-20-2012

Hi,

Finally, I am able to get the content of the vpxd log file (Hope it is the right log file to be used) and get the following information. Is there any clue what is happening every minute ? There are other ESXi Hosts in other clusters (Other Sites). Those in trouble are highlighed - ESX1 & ESX2.

++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

2012-08-21T11:43:14.985+10:00 [04572 info 'Default' opID=3b964e39] [VpxLRO] -- FINISH task-internal-110549 -- -- vim.ServiceInstance.retrieveContent -- 52e9419e-3e3a-76cd-ada2-059cd7c593fa(52ca0cfd-0fb0-1c2d-6594-a2d3aed55e4a)

2012-08-21T11:43:18.245+10:00 [04636 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:20.539+10:00 [04564 info 'Default' opID=HB-host-2698@12247-305a42b6] [VpxLRO] -- BEGIN task-internal-110550 -- host-2698 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:20.539+10:00 [04564 info 'Default' opID=HB-host-2698@12247-305a42b6] [VpxdHostSync] Synchronizing host: host-2698 (ESXA.mycompany.com, 192.168.15.3)

2012-08-21T11:43:20.554+10:00 [04564 info 'Default' opID=HB-host-2698@12247-305a42b6] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:20.570+10:00 [04636 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:20.648+10:00 [04636 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:20.648+10:00 [04564 info 'Default' opID=HB-host-2698@12247-305a42b6] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:20.648+10:00 [04564 info 'Default' opID=HB-host-2698@12247-305a42b6] [VpxdHostSync] Retrieved host update to 12247 for host-2698

2012-08-21T11:43:20.679+10:00 [04564 info 'Default' opID=HB-host-2698@12247-305a42b6] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXA.mycompany.com is not set

2012-08-21T11:43:20.679+10:00 [04564 info 'Default' opID=HB-host-2698@12247-305a42b6] [VpxdHostSync] Completed host synchronization for host-2698

2012-08-21T11:43:20.679+10:00 [04564 info 'Default' opID=HB-host-2698@12247-305a42b6] [VpxLRO] -- FINISH task-internal-110550 -- host-2698 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:26.014+10:00 [04608 info 'Default' opID=HB-host-7254@42311-617032e7] [VpxLRO] -- BEGIN task-internal-110551 -- host-7254 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:26.014+10:00 [04608 info 'Default' opID=HB-host-7254@42311-617032e7] [VpxdHostSync] Synchronizing host: host-7254 (ESXB.mycompany.com, 192.168.15.237)

2012-08-21T11:43:26.030+10:00 [04608 info 'Default' opID=HB-host-7254@42311-617032e7] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:26.030+10:00 [04600 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:26.108+10:00 [04600 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:26.124+10:00 [04600 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:26.124+10:00 [04608 info 'Default' opID=HB-host-7254@42311-617032e7] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:26.124+10:00 [04608 info 'Default' opID=HB-host-7254@42311-617032e7] [VpxdHostSync] Retrieved host update to 42311 for host-7254

2012-08-21T11:43:26.139+10:00 [04608 info 'Default' opID=HB-host-7254@42311-617032e7] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXB.mycompany.com is not set

2012-08-21T11:43:26.139+10:00 [04608 info 'Default' opID=HB-host-7254@42311-617032e7] [VpxdHostSync] Completed host synchronization for host-7254

2012-08-21T11:43:26.139+10:00 [04608 info 'Default' opID=HB-host-7254@42311-617032e7] [VpxLRO] -- FINISH task-internal-110551 -- host-7254 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:28.183+10:00 [04572 info 'Default' opID=HB-host-128@59047-7e2338e1] [VpxLRO] -- BEGIN task-internal-110552 -- host-128 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:28.183+10:00 [04572 info 'Default' opID=HB-host-128@59047-7e2338e1] [VpxdHostSync] Synchronizing host: host-128 (ESXC.mycompany.com, 192.168.19.221)

2012-08-21T11:43:28.183+10:00 [04572 info 'Default' opID=HB-host-128@59047-7e2338e1] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:28.198+10:00 [04572 info 'Default' opID=HB-host-128@59047-7e2338e1] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:28.214+10:00 [04596 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:28.276+10:00 [04596 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:28.292+10:00 [04596 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:28.292+10:00 [04572 info 'Default' opID=HB-host-128@59047-7e2338e1] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:28.292+10:00 [04572 info 'Default' opID=HB-host-128@59047-7e2338e1] [VpxdHostSync] Retrieved host update to 59047 for host-128

2012-08-21T11:43:28.308+10:00 [04572 info 'Default' opID=HB-host-128@59047-7e2338e1] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXC.mycompany.com is not set

2012-08-21T11:43:28.323+10:00 [04572 info 'Default' opID=HB-host-128@59047-7e2338e1] [VpxdHostSync] Completed host synchronization for host-128

2012-08-21T11:43:28.323+10:00 [04572 info 'Default' opID=HB-host-128@59047-7e2338e1] [VpxLRO] -- FINISH task-internal-110552 -- host-128 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:40.273+10:00 [04636 info 'Default' opID=HB-host-7549@16865-96ff4cc4] [VpxLRO] -- BEGIN task-internal-110553 -- host-7549 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:40.273+10:00 [04636 info 'Default' opID=HB-host-7549@16865-96ff4cc4] [VpxdHostSync] Synchronizing host: host-7549 (ESX1.mycompany.com, 192.168.55.238)

2012-08-21T11:43:40.289+10:00 [04636 info 'Default' opID=HB-host-7549@16865-96ff4cc4] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:40.304+10:00 [04636 info 'Default' opID=HB-host-7549@16865-96ff4cc4] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:40.367+10:00 [04576 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:40.382+10:00 [04576 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:40.382+10:00 [04636 info 'Default' opID=HB-host-7549@16865-96ff4cc4] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:40.398+10:00 [04636 info 'Default' opID=HB-host-7549@16865-96ff4cc4] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:40.398+10:00 [04636 info 'Default' opID=HB-host-7549@16865-96ff4cc4] [VpxdHostSync] Retrieved host update to 16865 for host-7549

2012-08-21T11:43:40.398+10:00 [04636 info 'Default' opID=HB-host-7549@16865-96ff4cc4] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESX1.mycompany.com is not set

2012-08-21T11:43:40.398+10:00 [04636 info 'Default' opID=HB-host-7549@16865-96ff4cc4] [VpxdHostSync] Completed host synchronization for host-7549

2012-08-21T11:43:40.398+10:00 [04636 info 'Default' opID=HB-host-7549@16865-96ff4cc4] [VpxLRO] -- FINISH task-internal-110553 -- host-7549 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:48.182+10:00 [04640 info 'Default' opID=HB-host-128@59048-ff024f41] [VpxLRO] -- BEGIN task-internal-110554 -- host-128 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:48.182+10:00 [04640 info 'Default' opID=HB-host-128@59048-ff024f41] [VpxdHostSync] Synchronizing host: host-128 (ESXC.mycompany.com, 192.168.19.221)

2012-08-21T11:43:51.224+10:00 [04640 warning 'VpxProfiler' opID=HB-host-128@59048-ff024f41] ClientAdapterBase::InvokeOnSoap: (ESXC.mycompany.com, vpxapi.VpxaService.retrieveChanges) [SoapRpcTime] took 3042 ms

2012-08-21T11:43:51.224+10:00 [04640 info 'Default' opID=HB-host-128@59048-ff024f41] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:51.240+10:00 [04640 info 'Default' opID=HB-host-128@59048-ff024f41] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:51.240+10:00 [04576 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:51.302+10:00 [04576 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:51.318+10:00 [04576 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:51.318+10:00 [04640 info 'Default' opID=HB-host-128@59048-ff024f41] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:51.333+10:00 [04640 info 'Default' opID=HB-host-128@59048-ff024f41] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:51.333+10:00 [04640 warning 'VpxProfiler' opID=HB-host-128@59048-ff024f41] [VpxdHostSync] GetChanges host:ESXC.mycompany.com (192.168.19.221) [GetChangesTime] took 3151 ms

2012-08-21T11:43:51.333+10:00 [04640 info 'Default' opID=HB-host-128@59048-ff024f41] [VpxdHostSync] Retrieved host update to 59048 for host-128

2012-08-21T11:43:51.349+10:00 [04640 info 'Default' opID=HB-host-128@59048-ff024f41] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXC.mycompany.com is not set

2012-08-21T11:43:51.349+10:00 [04640 info 'Default' opID=HB-host-128@59048-ff024f41] [VpxdHostSync] Completed host synchronization for host-128

2012-08-21T11:43:51.349+10:00 [04640 warning 'VpxProfiler' opID=HB-host-128@59048-ff024f41] [VpxdHostSync] DoHostSync:0000000009DAAED0 [DoHostSyncTime] took 3166 ms

2012-08-21T11:43:51.349+10:00 [04640 warning 'VpxProfiler' opID=HB-host-128@59048-ff024f41] InvtHostSyncLRO::StartWork [HostSyncTime] took 3166 ms

2012-08-21T11:43:51.349+10:00 [04640 info 'Default' opID=HB-host-128@59048-ff024f41] [VpxLRO] -- FINISH task-internal-110554 -- host-128 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:56.014+10:00 [04612 info 'Default' opID=HB-host-7254@42313-fad583aa] [VpxLRO] -- BEGIN task-internal-110555 -- host-7254 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:43:56.014+10:00 [04612 info 'Default' opID=HB-host-7254@42313-fad583aa] [VpxdHostSync] Synchronizing host: host-7254 (ESXB.mycompany.com, 192.168.15.237)

2012-08-21T11:43:56.029+10:00 [04612 info 'Default' opID=HB-host-7254@42313-fad583aa] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:56.029+10:00 [04608 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:56.107+10:00 [04608 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:56.123+10:00 [04608 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:56.123+10:00 [04612 info 'Default' opID=HB-host-7254@42313-fad583aa] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:43:57.137+10:00 [04612 info 'Default' opID=HB-host-7254@42313-fad583aa] [VpxdHostSync] Retrieved host update to 42313 for host-7254

2012-08-21T11:43:57.152+10:00 [04612 info 'Default' opID=HB-host-7254@42313-fad583aa] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXB.mycompany.com is not set

2012-08-21T11:43:57.152+10:00 [04612 info 'Default' opID=HB-host-7254@42313-fad583aa] [VpxdHostSync] Completed host synchronization for host-7254

2012-08-21T11:43:57.152+10:00 [04612 info 'Default' opID=HB-host-7254@42313-fad583aa] [VpxLRO] -- FINISH task-internal-110555 -- host-7254 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:08.182+10:00 [04648 info 'Default' opID=HB-host-128@59049-f074eeea] [VpxLRO] -- BEGIN task-internal-110556 -- host-128 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:08.182+10:00 [04648 info 'Default' opID=HB-host-128@59049-f074eeea] [VpxdHostSync] Synchronizing host: host-128 (ESXC.mycompany.com, 192.168.19.221)

2012-08-21T11:44:08.229+10:00 [04648 info 'Default' opID=HB-host-128@59049-f074eeea] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:08.244+10:00 [04652 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:08.291+10:00 [04652 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:08.307+10:00 [04652 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:08.307+10:00 [04648 info 'Default' opID=HB-host-128@59049-f074eeea] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:08.322+10:00 [04648 info 'Default' opID=HB-host-128@59049-f074eeea] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:08.322+10:00 [04648 info 'Default' opID=HB-host-128@59049-f074eeea] [VpxdHostSync] Retrieved host update to 59049 for host-128

2012-08-21T11:44:08.525+10:00 [04648 info 'Default' opID=HB-host-128@59049-f074eeea] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXC.mycompany.com is not set

2012-08-21T11:44:08.525+10:00 [04648 info 'Default' opID=HB-host-128@59049-f074eeea] [VpxdHostSync] Completed host synchronization for host-128

2012-08-21T11:44:08.525+10:00 [04648 info 'Default' opID=HB-host-128@59049-f074eeea] [VpxLRO] -- FINISH task-internal-110556 -- host-128 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:10.413+10:00 [04620 warning 'VpxProfiler' opID=HB-host-7787@5999-8074fb62-SWI-96d6724e] VpxUtil_InvokeWithOpId [TotalTime] took 55599 ms

2012-08-21T11:44:11.520+10:00 [04628 info 'Default' opID=SWI-2561d58b] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:12.628+10:00 [04636 info 'Default' opID=9ace4141] [VpxLRO] -- BEGIN task-internal-110557 -- -- vim.PerformanceManager.queryStats -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:12.628+10:00 [04636 info 'Default' opID=9ace4141] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:12.799+10:00 [04636 info 'Default' opID=9ace4141] [VpxLRO] -- FINISH task-internal-110557 -- -- vim.PerformanceManager.queryStats -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.096+10:00 [04580 info 'Default' opID=20898be3] [VpxLRO] -- BEGIN task-internal-110558 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.096+10:00 [04580 info 'Default' opID=20898be3] [VpxLRO] -- FINISH task-internal-110558 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.205+10:00 [04608 info 'Default' opID=e45e252e] [VpxLRO] -- BEGIN task-internal-110559 -- -- vim.PerformanceManager.queryStats -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.205+10:00 [04608 info 'Default' opID=e45e252e] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:13.221+10:00 [04608 info 'Default' opID=e45e252e] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:13.314+10:00 [04596 info 'Default' opID=9d4f37ab] [VpxLRO] -- BEGIN task-internal-110560 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.314+10:00 [04596 info 'Default' opID=9d4f37ab] [VpxLRO] -- FINISH task-internal-110560 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.533+10:00 [01228 info 'Default' opID=28291c2b] [VpxLRO] -- BEGIN task-internal-110561 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.533+10:00 [01228 info 'Default' opID=28291c2b] [VpxLRO] -- FINISH task-internal-110561 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.595+10:00 [04608 info 'Default' opID=e45e252e] [VpxLRO] -- FINISH task-internal-110559 -- -- vim.PerformanceManager.queryStats -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.767+10:00 [04612 info 'Default' opID=1cc420db] [VpxLRO] -- BEGIN task-internal-110562 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.767+10:00 [04612 info 'Default' opID=1cc420db] [VpxLRO] -- FINISH task-internal-110562 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.985+10:00 [04596 info 'Default' opID=14848531] [VpxLRO] -- BEGIN task-internal-110563 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:13.985+10:00 [04596 info 'Default' opID=14848531] [VpxLRO] -- FINISH task-internal-110563 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:14.453+10:00 [04608 info 'Default' opID=444afcb7] [VpxLRO] -- BEGIN task-internal-110564 -- -- vim.TaskManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:14.453+10:00 [04608 info 'Default' opID=444afcb7] [VpxLRO] -- FINISH task-internal-110564 -- -- vim.TaskManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:14.671+10:00 [04648 info 'Default' opID=57235d82] [VpxLRO] -- BEGIN task-internal-110565 -- -- vim.TaskManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:14.671+10:00 [04648 info 'Default' opID=57235d82] [VpxLRO] -- FINISH task-internal-110565 -- -- vim.TaskManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:14.890+10:00 [04608 info 'Default' opID=de56aeae] [VpxLRO] -- BEGIN task-internal-110566 -- -- vim.event.EventManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:14.890+10:00 [04608 info 'Default' opID=de56aeae] [VpxLRO] -- FINISH task-internal-110566 -- -- vim.event.EventManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:14.999+10:00 [04612 info 'Default' opID=ac7450e8] [VpxLRO] -- BEGIN task-internal-110567 -- -- vim.ServiceInstance.retrieveContent -- 52e9419e-3e3a-76cd-ada2-059cd7c593fa(52ca0cfd-0fb0-1c2d-6594-a2d3aed55e4a)

2012-08-21T11:44:14.999+10:00 [04612 info 'Default' opID=ac7450e8] [VpxLRO] -- FINISH task-internal-110567 -- -- vim.ServiceInstance.retrieveContent -- 52e9419e-3e3a-76cd-ada2-059cd7c593fa(52ca0cfd-0fb0-1c2d-6594-a2d3aed55e4a)

2012-08-21T11:44:15.108+10:00 [04648 info 'Default' opID=eecad19e] [VpxLRO] -- BEGIN task-internal-110568 -- -- vim.event.EventHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:15.108+10:00 [04648 info 'Default' opID=eecad19e] [VpxLRO] -- FINISH task-internal-110568 -- -- vim.event.EventHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:15.342+10:00 [04604 info 'Default' opID=a5622056] [VpxLRO] -- BEGIN task-internal-110569 -- -- vim.event.EventHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:15.342+10:00 [04604 info 'Default' opID=a5622056] [VpxLRO] -- FINISH task-internal-110569 -- -- vim.event.EventHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:15.561+10:00 [03444 info 'Default' opID=fd0b74c4] [VpxLRO] -- BEGIN task-internal-110570 -- -- vim.TaskHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:15.561+10:00 [03444 info 'Default' opID=fd0b74c4] [VpxLRO] -- FINISH task-internal-110570 -- -- vim.TaskHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:15.779+10:00 [04588 info 'Default' opID=34932b1b] [VpxLRO] -- BEGIN task-internal-110571 -- -- vim.TaskHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:15.779+10:00 [04588 info 'Default' opID=34932b1b] [VpxLRO] -- FINISH task-internal-110571 -- -- vim.TaskHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:44:20.568+10:00 [03444 info 'Default' opID=HB-host-2698@12249-55c47fbe] [VpxLRO] -- BEGIN task-internal-110572 -- host-2698 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:20.568+10:00 [03444 info 'Default' opID=HB-host-2698@12249-55c47fbe] [VpxdHostSync] Synchronizing host: host-2698 (ESXA.mycompany.com, 192.168.15.3)

2012-08-21T11:44:20.568+10:00 [03444 info 'Default' opID=HB-host-2698@12249-55c47fbe] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:20.584+10:00 [03444 info 'Default' opID=HB-host-2698@12249-55c47fbe] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:20.599+10:00 [04604 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:20.693+10:00 [04604 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:20.709+10:00 [04604 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:20.709+10:00 [03444 info 'Default' opID=HB-host-2698@12249-55c47fbe] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:21.723+10:00 [03444 info 'Default' opID=HB-host-2698@12249-55c47fbe] [VpxdHostSync] Retrieved host update to 12249 for host-2698

2012-08-21T11:44:21.754+10:00 [03444 info 'Default' opID=HB-host-2698@12249-55c47fbe] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXA.mycompany.com is not set

2012-08-21T11:44:21.769+10:00 [03444 info 'Default' opID=HB-host-2698@12249-55c47fbe] [VpxdHostSync] Completed host synchronization for host-2698

2012-08-21T11:44:21.769+10:00 [03444 info 'Default' opID=HB-host-2698@12249-55c47fbe] [VpxLRO] -- FINISH task-internal-110572 -- host-2698 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:24.734+10:00 [04620 info 'Default' opID=HB-host-7787@6000-2f415e2e] [VpxLRO] -- BEGIN task-internal-110573 -- host-7787 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:24.734+10:00 [04620 info 'Default' opID=HB-host-7787@6000-2f415e2e] [VpxdHostSync] Synchronizing host: host-7787 (ESX2.mycompany.com, 192.168.55.221)

2012-08-21T11:44:24.749+10:00 [04620 info 'Default' opID=HB-host-7787@6000-2f415e2e] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:24.765+10:00 [04620 info 'Default' opID=HB-host-7787@6000-2f415e2e] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:24.827+10:00 [04592 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:24.843+10:00 [04592 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:24.858+10:00 [04620 info 'Default' opID=HB-host-7787@6000-2f415e2e] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:24.858+10:00 [04620 info 'Default' opID=HB-host-7787@6000-2f415e2e] [VpxdHostSync] Retrieved host update to 6000 for host-7787

2012-08-21T11:44:24.858+10:00 [04620 info 'Default' opID=HB-host-7787@6000-2f415e2e] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESX2.mycompany.com is not set

2012-08-21T11:44:24.874+10:00 [04620 info 'Default' opID=HB-host-7787@6000-2f415e2e] [VpxdHostSync] Completed host synchronization for host-7787

2012-08-21T11:44:24.874+10:00 [04620 info 'Default' opID=HB-host-7787@6000-2f415e2e] [VpxLRO] -- FINISH task-internal-110573 -- host-7787 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:26.028+10:00 [04572 info 'Default' opID=HB-host-7254@42314-9632d97b] [VpxLRO] -- BEGIN task-internal-110574 -- host-7254 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:26.028+10:00 [04572 info 'Default' opID=HB-host-7254@42314-9632d97b] [VpxdHostSync] Synchronizing host: host-7254 (ESXB.mycompany.com, 192.168.15.237)

2012-08-21T11:44:26.028+10:00 [04572 info 'Default' opID=HB-host-7254@42314-9632d97b] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:26.044+10:00 [04612 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:26.122+10:00 [04612 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:26.138+10:00 [04572 info 'Default' opID=HB-host-7254@42314-9632d97b] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:26.138+10:00 [04572 info 'Default' opID=HB-host-7254@42314-9632d97b] [VpxdHostSync] Retrieved host update to 42314 for host-7254

2012-08-21T11:44:26.184+10:00 [04572 info 'Default' opID=HB-host-7254@42314-9632d97b] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXB.mycompany.com is not set

2012-08-21T11:44:26.200+10:00 [04572 info 'Default' opID=HB-host-7254@42314-9632d97b] [VpxdHostSync] Completed host synchronization for host-7254

2012-08-21T11:44:26.200+10:00 [04572 info 'Default' opID=HB-host-7254@42314-9632d97b] [VpxLRO] -- FINISH task-internal-110574 -- host-7254 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:28.197+10:00 [04648 info 'Default' opID=HB-host-128@59050-c08816ac] [VpxLRO] -- BEGIN task-internal-110575 -- host-128 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:28.197+10:00 [04648 info 'Default' opID=HB-host-128@59050-c08816ac] [VpxdHostSync] Synchronizing host: host-128 (ESXC.mycompany.com, 192.168.19.221)

2012-08-21T11:44:28.197+10:00 [04648 info 'Default' opID=HB-host-128@59050-c08816ac] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:28.212+10:00 [04648 info 'Default' opID=HB-host-128@59050-c08816ac] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:28.228+10:00 [04636 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:28.290+10:00 [04636 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:28.306+10:00 [04636 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:28.306+10:00 [04648 info 'Default' opID=HB-host-128@59050-c08816ac] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:28.306+10:00 [04648 info 'Default' opID=HB-host-128@59050-c08816ac] [VpxdHostSync] Retrieved host update to 59050 for host-128

2012-08-21T11:44:28.337+10:00 [04648 info 'Default' opID=HB-host-128@59050-c08816ac] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXC.mycompany.com is not set

2012-08-21T11:44:28.337+10:00 [04648 info 'Default' opID=HB-host-128@59050-c08816ac] [VpxdHostSync] Completed host synchronization for host-128

2012-08-21T11:44:28.337+10:00 [04648 info 'Default' opID=HB-host-128@59050-c08816ac] [VpxLRO] -- FINISH task-internal-110575 -- host-128 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:32.627+10:00 [04648 info 'Default' opID=task-internal-1-2f7226f8-7e] [VpxLRO] -- BEGIN task-internal-110576 -- -- AskRefreshDrmRecLro --

2012-08-21T11:44:32.627+10:00 [04648 info 'Default' opID=task-internal-1-2f7226f8-7e] [IsIpmiInfoValidInt] Host ESXA.mycompany.com: a field is null, empty or over-sized.

2012-08-21T11:44:32.627+10:00 [04648 info 'Default' opID=task-internal-1-2f7226f8-7e] [IsIpmiInfoValidInt] Host ESXB.mycompany.com: a field is null, empty or over-sized.

2012-08-21T11:44:32.643+10:00 [04592 info 'StackTracer' opID=task-internal-1-2f7226f8-7e-SWI-532aab7b] [4592] Enter DAS_PROFILE UpdateDasStatus

2012-08-21T11:44:32.643+10:00 [04592 info 'StackTracer' opID=task-internal-1-2f7226f8-7e-SWI-532aab7b] [4592] Exit DAS_PROFILE UpdateDasStatus (0 ms)

2012-08-21T11:44:32.658+10:00 [04648 info 'Default' opID=task-internal-1-2f7226f8-7e] [Drm] Drmdump written: C:\ProgramData\VMware\VMware VirtualCenter\Logs/drmdump/cluster967/307174704-proposeActions.dump

2012-08-21T11:44:32.674+10:00 [04648 info 'Default' opID=task-internal-1-2f7226f8-7e] [Drm] host-on LogHostDemand: host ESXD.mycompany.comcpu 1735 mem 3389, host ESXA.mycompany.com cpu 1479 mem 3335, host ESXB.mycompany.com cpu 619 mem 1908, TOTAL cpu 3833 mem 8632

2012-08-21T11:44:32.674+10:00 [04648 info 'Default' opID=task-internal-1-2f7226f8-7e] [Drm] host-off LogHostDemand: host ESXD.mycompany.comcpu 1874 mem 3737, host ESXA.mycompany.com cpu 2305 mem 4459, host ESXB.mycompany.com cpu 972 mem 2251, TOTAL cpu 5151 mem 10447

2012-08-21T11:44:32.674+10:00 [04648 info 'Default' opID=task-internal-1-2f7226f8-7e] [Drm] LogActiveCapacity: cpu 49476 mem 119683

2012-08-21T11:44:32.690+10:00 [04648 warning 'VpxProfiler' opID=task-internal-1-2f7226f8-7e] Time taken for DRS under LRO [CallingProposeActions] took 46 ms

2012-08-21T11:44:32.705+10:00 [04648 warning 'VpxProfiler' opID=task-internal-1-2f7226f8-7e] Time taken for DRS under LRO [AskForDrmRecommendations] took 78 ms

2012-08-21T11:44:32.705+10:00 [04648 warning 'VpxProfiler' opID=task-internal-1-2f7226f8-7e] Time taken for DRS under LRO [AskAndRefreshDrmRecommendations] took 78 ms

2012-08-21T11:44:32.705+10:00 [04648 info 'Default' opID=task-internal-1-2f7226f8-7e] [VpxLRO] -- FINISH task-internal-110576 -- -- AskRefreshDrmRecLro --

2012-08-21T11:44:37.713+10:00 [04620 info 'Default' opID=task-internal-1-2f7226f8-ef] [VpxLRO] -- BEGIN task-internal-110577 -- -- AskRefreshDrmRecLro --

2012-08-21T11:44:37.713+10:00 [04620 info 'Default' opID=task-internal-1-2f7226f8-ef] [IsIpmiInfoValidInt] Host ESX1.mycompany.com: a field is null, empty or over-sized.

2012-08-21T11:44:37.713+10:00 [04620 info 'Default' opID=task-internal-1-2f7226f8-ef] [IsIpmiInfoValidInt] Host ESX2.mycompany.com: a field is null, empty or over-sized.

2012-08-21T11:44:37.728+10:00 [04584 info 'StackTracer' opID=task-internal-1-2f7226f8-ef-SWI-5f06320f] [4584] Enter DAS_PROFILE UpdateDasStatus

2012-08-21T11:44:37.728+10:00 [04584 info 'StackTracer' opID=task-internal-1-2f7226f8-ef-SWI-5f06320f] [4584] Exit DAS_PROFILE UpdateDasStatus (0 ms)

2012-08-21T11:44:37.728+10:00 [04620 info 'Default' opID=task-internal-1-2f7226f8-ef] [Drm] Drmdump written: C:\ProgramData\VMware\VMware VirtualCenter\Logs/drmdump/cluster7541/307179790-proposeActions.dump

2012-08-21T11:44:37.744+10:00 [04620 info 'Default' opID=task-internal-1-2f7226f8-ef] [Drm] host-on LogHostDemand: host ESX1.mycompany.com cpu 183 mem 539, host ESX2.mycompany.com cpu 1287 mem 2630, TOTAL cpu 1470 mem 3169

2012-08-21T11:44:37.744+10:00 [04620 info 'Default' opID=task-internal-1-2f7226f8-ef] [Drm] host-off LogHostDemand: host ESX1.mycompany.com cpu 142 mem 740, host ESX2.mycompany.com cpu 2403 mem 3693, TOTAL cpu 2545 mem 4433

2012-08-21T11:44:37.744+10:00 [04620 info 'Default' opID=task-internal-1-2f7226f8-ef] [Drm] LogActiveCapacity: cpu 66738 mem 122077

2012-08-21T11:44:37.760+10:00 [04620 warning 'VpxProfiler' opID=task-internal-1-2f7226f8-ef] Time taken for DRS under LRO [CallingProposeActions] took 46 ms

2012-08-21T11:44:37.775+10:00 [04620 warning 'VpxProfiler' opID=task-internal-1-2f7226f8-ef] Time taken for DRS under LRO [AskForDrmRecommendations] took 62 ms

2012-08-21T11:44:37.775+10:00 [04620 warning 'VpxProfiler' opID=task-internal-1-2f7226f8-ef] Time taken for DRS under LRO [AskAndRefreshDrmRecommendations] took 62 ms

2012-08-21T11:44:37.775+10:00 [04620 info 'Default' opID=task-internal-1-2f7226f8-ef] [VpxLRO] -- FINISH task-internal-110577 -- -- AskRefreshDrmRecLro --

2012-08-21T11:44:50.287+10:00 [04596 info 'Default' opID=HB-host-7549@16866-4215572] [VpxLRO] -- BEGIN task-internal-110578 -- host-7549 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:50.287+10:00 [04596 info 'Default' opID=HB-host-7549@16866-4215572] [VpxdHostSync] Synchronizing host: host-7549 (ESX1.mycompany.com, 192.168.55.238)

2012-08-21T11:44:50.318+10:00 [04596 info 'Default' opID=HB-host-7549@16866-4215572] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:50.333+10:00 [04596 info 'Default' opID=HB-host-7549@16866-4215572] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:50.333+10:00 [04620 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:50.396+10:00 [04620 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:50.411+10:00 [04620 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:50.411+10:00 [04596 info 'Default' opID=HB-host-7549@16866-4215572] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:50.427+10:00 [04596 info 'Default' opID=HB-host-7549@16866-4215572] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:50.427+10:00 [04596 info 'Default' opID=HB-host-7549@16866-4215572] [VpxdHostSync] Retrieved host update to 16866 for host-7549

2012-08-21T11:44:50.427+10:00 [04596 info 'Default' opID=HB-host-7549@16866-4215572] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESX1.mycompany.com is not set

2012-08-21T11:44:50.427+10:00 [04596 info 'Default' opID=HB-host-7549@16866-4215572] [VpxdHostSync] Completed host synchronization for host-7549

2012-08-21T11:44:50.427+10:00 [04596 info 'Default' opID=HB-host-7549@16866-4215572] [VpxLRO] -- FINISH task-internal-110578 -- host-7549 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:56.028+10:00 [03444 info 'Default' opID=HB-host-7254@42316-1718de97] [VpxLRO] -- BEGIN task-internal-110579 -- host-7254 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:44:56.028+10:00 [03444 info 'Default' opID=HB-host-7254@42316-1718de97] [VpxdHostSync] Synchronizing host: host-7254 (ESXB.mycompany.com, 192.168.15.237)

2012-08-21T11:44:56.043+10:00 [03444 info 'Default' opID=HB-host-7254@42316-1718de97] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:56.043+10:00 [04640 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:56.121+10:00 [04640 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:56.137+10:00 [04640 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:56.137+10:00 [03444 info 'Default' opID=HB-host-7254@42316-1718de97] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:44:56.137+10:00 [03444 info 'Default' opID=HB-host-7254@42316-1718de97] [VpxdHostSync] Retrieved host update to 42316 for host-7254

2012-08-21T11:44:56.168+10:00 [03444 info 'Default' opID=HB-host-7254@42316-1718de97] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXB.mycompany.com is not set

2012-08-21T11:44:56.168+10:00 [03444 info 'Default' opID=HB-host-7254@42316-1718de97] [VpxdHostSync] Completed host synchronization for host-7254

2012-08-21T11:44:56.168+10:00 [03444 info 'Default' opID=HB-host-7254@42316-1718de97] [VpxLRO] -- FINISH task-internal-110579 -- host-7254 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:45:00.006+10:00 [04608 info 'Default' opID=SWI-f6819806] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:00.006+10:00 [04608 info 'Default' opID=SWI-f6819806] [VpxDrmStatsManager::GetMetricsToCollect] No datastores requiring stats collection on host vim.HostSystem:host-2698, early return

2012-08-21T11:45:00.567+10:00 [03444 info 'Default' opID=HB-host-2698@12250-49fb748d] [VpxLRO] -- BEGIN task-internal-110580 -- host-2698 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:45:00.567+10:00 [03444 info 'Default' opID=HB-host-2698@12250-49fb748d] [VpxdHostSync] Synchronizing host: host-2698 (ESXA.mycompany.com, 192.168.15.3)

2012-08-21T11:45:00.583+10:00 [03444 info 'Default' opID=HB-host-2698@12250-49fb748d] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:00.598+10:00 [04640 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:00.692+10:00 [04640 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:00.708+10:00 [03444 info 'Default' opID=HB-host-2698@12250-49fb748d] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:01.722+10:00 [03444 info 'Default' opID=HB-host-2698@12250-49fb748d] [VpxdHostSync] Retrieved host update to 12250 for host-2698

2012-08-21T11:45:01.753+10:00 [03444 info 'Default' opID=HB-host-2698@12250-49fb748d] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXA.mycompany.com is not set

2012-08-21T11:45:01.768+10:00 [03444 info 'Default' opID=HB-host-2698@12250-49fb748d] [VpxdHostSync] Completed host synchronization for host-2698

2012-08-21T11:45:01.768+10:00 [03444 info 'Default' opID=HB-host-2698@12250-49fb748d] [VpxLRO] -- FINISH task-internal-110580 -- host-2698 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:45:11.534+10:00 [04628 info 'Default' opID=SWI-2561d58b] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:15.325+10:00 [04592 info 'Default' opID=e6c21807] [VpxLRO] -- BEGIN task-internal-110581 -- -- vim.ServiceInstance.retrieveContent -- 52e9419e-3e3a-76cd-ada2-059cd7c593fa(52ca0cfd-0fb0-1c2d-6594-a2d3aed55e4a)

2012-08-21T11:45:15.325+10:00 [04592 info 'Default' opID=e6c21807] [VpxLRO] -- FINISH task-internal-110581 -- -- vim.ServiceInstance.retrieveContent -- 52e9419e-3e3a-76cd-ada2-059cd7c593fa(52ca0cfd-0fb0-1c2d-6594-a2d3aed55e4a)

2012-08-21T11:45:20.442+10:00 [04564 warning 'VpxProfiler' opID=HB-host-7787@6000-2f415e2e-SWI-4f18542] VpxUtil_InvokeWithOpId [TotalTime] took 55583 ms

2012-08-21T11:45:20.582+10:00 [04564 info 'Default' opID=HB-host-2698@12252-8d0687b8] [VpxLRO] -- BEGIN task-internal-110582 -- host-2698 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:45:20.582+10:00 [04564 info 'Default' opID=HB-host-2698@12252-8d0687b8] [VpxdHostSync] Synchronizing host: host-2698 (ESXA.mycompany.com, 192.168.15.3)

2012-08-21T11:45:20.582+10:00 [04564 info 'Default' opID=HB-host-2698@12252-8d0687b8] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:20.598+10:00 [04564 info 'Default' opID=HB-host-2698@12252-8d0687b8] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:20.598+10:00 [04600 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:20.691+10:00 [04600 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:20.691+10:00 [04564 info 'Default' opID=HB-host-2698@12252-8d0687b8] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:20.707+10:00 [04564 info 'Default' opID=HB-host-2698@12252-8d0687b8] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:21.721+10:00 [04564 info 'Default' opID=HB-host-2698@12252-8d0687b8] [VpxdHostSync] Retrieved host update to 12252 for host-2698

2012-08-21T11:45:21.752+10:00 [04564 info 'Default' opID=HB-host-2698@12252-8d0687b8] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESXA.mycompany.com is not set

2012-08-21T11:45:21.752+10:00 [04564 info 'Default' opID=HB-host-2698@12252-8d0687b8] [VpxdHostSync] Completed host synchronization for host-2698

2012-08-21T11:45:21.752+10:00 [04564 info 'Default' opID=HB-host-2698@12252-8d0687b8] [VpxLRO] -- FINISH task-internal-110582 -- host-2698 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:45:28.960+10:00 [04636 info 'Default' opID=A14E6F50-000002D9] [VpxLRO] -- BEGIN task-internal-110583 -- -- vim.view.InventoryView.openFolder -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:28.960+10:00 [04636 info 'Default' opID=A14E6F50-000002D9] [VpxLRO] -- FINISH task-internal-110583 -- -- vim.view.InventoryView.openFolder -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:28.991+10:00 [04604 info 'Default' opID=A14E6F50-000002DB] [VpxLRO] -- BEGIN task-internal-110584 -- -- vmodl.query.PropertyCollector.retrieveContents -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:28.991+10:00 [04588 info 'Default' opID=ffd87847] [VpxLRO] -- BEGIN task-internal-110585 -- -- vim.PerformanceManager.queryStats -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:28.991+10:00 [04604 info 'Default' opID=A14E6F50-000002DB] [VpxLRO] -- FINISH task-internal-110584 -- -- vmodl.query.PropertyCollector.retrieveContents -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:28.991+10:00 [04588 info 'Default' opID=ffd87847] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:28.991+10:00 [04584 info 'Default' opID=A14E6F50-000002DC] [VpxLRO] -- BEGIN task-internal-110586 -- -- vim.view.ListView.modify -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:28.991+10:00 [04584 info 'Default' opID=A14E6F50-000002DC] [VpxLRO] -- FINISH task-internal-110586 -- -- vim.view.ListView.modify -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:28.991+10:00 [04588 info 'Default' opID=ffd87847] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:28.991+10:00 [04568 info 'Default' opID=A14E6F50-000002DD] [VpxLRO] -- BEGIN task-internal-110587 -- -- vim.view.InventoryView.openFolder -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:28.991+10:00 [04568 info 'Default' opID=A14E6F50-000002DD] [VpxLRO] -- FINISH task-internal-110587 -- -- vim.view.InventoryView.openFolder -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:29.022+10:00 [03444 info 'Default' opID=A14E6F50-000002DE] [VpxLRO] -- BEGIN task-internal-110588 -- -- vmodl.query.PropertyCollector.retrieveContents -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:29.022+10:00 [03444 info 'Default' opID=A14E6F50-000002DE] [VpxLRO] -- FINISH task-internal-110588 -- -- vmodl.query.PropertyCollector.retrieveContents -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:29.022+10:00 [03444 info 'Default' opID=A14E6F50-000002DF] [VpxLRO] -- BEGIN task-internal-110589 -- -- vim.view.ListView.modify -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:29.022+10:00 [03444 info 'Default' opID=A14E6F50-000002DF] [VpxLRO] -- FINISH task-internal-110589 -- -- vim.view.ListView.modify -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:29.038+10:00 [04604 info 'Default' opID=A14E6F50-000002E0] [VpxLRO] -- BEGIN task-internal-110590 -- -- vmodl.query.PropertyCollector.retrieveContents -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:29.038+10:00 [04604 info 'Default' opID=A14E6F50-000002E0] [VpxLRO] -- FINISH task-internal-110590 -- -- vmodl.query.PropertyCollector.retrieveContents -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:29.038+10:00 [03444 info 'Default' opID=A14E6F50-000002E1] [VpxLRO] -- BEGIN task-internal-110591 -- -- vim.view.ListView.modify -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:29.038+10:00 [03444 info 'Default' opID=A14E6F50-000002E1] [VpxLRO] -- FINISH task-internal-110591 -- -- vim.view.ListView.modify -- 52ac6c6f-d01a-67fa-edc5-7a49b347c807(52a11817-190b-e2c3-b599-769bb26de6b3)

2012-08-21T11:45:29.147+10:00 [04588 info 'Default' opID=ffd87847] [VpxLRO] -- FINISH task-internal-110585 -- -- vim.PerformanceManager.queryStats -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:29.272+10:00 [04568 info 'Default' opID=41176e9b] [VpxLRO] -- BEGIN task-internal-110592 -- -- vim.PerformanceManager.queryStats -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:29.287+10:00 [04568 info 'Default' opID=41176e9b] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:29.459+10:00 [04568 info 'Default' opID=41176e9b] [VpxLRO] -- FINISH task-internal-110592 -- -- vim.PerformanceManager.queryStats -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:29.974+10:00 [04580 info 'Default' opID=6e07fa5] [VpxLRO] -- BEGIN task-internal-110593 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:29.974+10:00 [04580 info 'Default' opID=6e07fa5] [VpxLRO] -- FINISH task-internal-110593 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:30.192+10:00 [04636 info 'Default' opID=7b2b2a9d] [VpxLRO] -- BEGIN task-internal-110594 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:30.192+10:00 [04636 info 'Default' opID=7b2b2a9d] [VpxLRO] -- FINISH task-internal-110594 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:30.410+10:00 [04648 info 'Default' opID=51a580f4] [VpxLRO] -- BEGIN task-internal-110595 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:30.410+10:00 [04648 info 'Default' opID=51a580f4] [VpxLRO] -- FINISH task-internal-110595 -- -- vim.HistoryCollector.remove -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:32.329+10:00 [03444 info 'Default' opID=826c47ee] [VpxLRO] -- BEGIN task-internal-110596 -- -- vim.TaskManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:32.329+10:00 [03444 info 'Default' opID=826c47ee] [VpxLRO] -- FINISH task-internal-110596 -- -- vim.TaskManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:32.548+10:00 [04612 info 'Default' opID=7a21e44f] [VpxLRO] -- BEGIN task-internal-110597 -- -- vim.TaskManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:32.548+10:00 [04612 info 'Default' opID=7a21e44f] [VpxLRO] -- FINISH task-internal-110597 -- -- vim.TaskManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:32.766+10:00 [01228 info 'Default' opID=df2e22] [VpxLRO] -- BEGIN task-internal-110598 -- -- vim.event.EventManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:32.766+10:00 [01228 info 'Default' opID=df2e22] [VpxLRO] -- FINISH task-internal-110598 -- -- vim.event.EventManager.createCollector -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:32.984+10:00 [04596 info 'Default' opID=7bf8d06c] [VpxLRO] -- BEGIN task-internal-110599 -- -- vim.event.EventHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:32.984+10:00 [04596 info 'Default' opID=7bf8d06c] [VpxLRO] -- FINISH task-internal-110599 -- -- vim.event.EventHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:33.203+10:00 [03444 info 'Default' opID=6bb24016] [VpxLRO] -- BEGIN task-internal-110600 -- -- vim.TaskHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:33.203+10:00 [03444 info 'Default' opID=6bb24016] [VpxLRO] -- FINISH task-internal-110600 -- -- vim.TaskHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:33.421+10:00 [04596 info 'Default' opID=788bfc04] [VpxLRO] -- BEGIN task-internal-110601 -- -- vim.TaskHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:33.421+10:00 [04596 info 'Default' opID=788bfc04] [VpxLRO] -- FINISH task-internal-110601 -- -- vim.TaskHistoryCollector.readNext -- 522f7482-c5ae-d9d1-8e77-6dc70394ce41(52492c6f-b112-d443-5435-1ce7dd348159)

2012-08-21T11:45:34.747+10:00 [01228 info 'Default' opID=HB-host-7787@6001-20a8c164] [VpxLRO] -- BEGIN task-internal-110602 -- host-7787 -- VpxdInvtHostSyncHostLRO.Synchronize --

2012-08-21T11:45:34.747+10:00 [01228 info 'Default' opID=HB-host-7787@6001-20a8c164] [VpxdHostSync] Synchronizing host: host-7787 (ESX2.mycompany.com, 192.168.55.221)

2012-08-21T11:45:34.747+10:00 [01228 info 'Default' opID=HB-host-7787@6001-20a8c164] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:34.763+10:00 [01228 info 'Default' opID=HB-host-7787@6001-20a8c164] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:34.778+10:00 [03676 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:34.825+10:00 [03676 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:34.841+10:00 [03676 info 'Default'] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:34.841+10:00 [01228 info 'Default' opID=HB-host-7787@6001-20a8c164] [ClientAdapterBase] InvokeOnSoap leaving

2012-08-21T11:45:35.855+10:00 [01228 info 'Default' opID=HB-host-7787@6001-20a8c164] [VpxdHostSync] Retrieved host update to 6001 for host-7787

2012-08-21T11:45:35.855+10:00 [01228 info 'Default' opID=HB-host-7787@6001-20a8c164] [VpxdInvtHost::SaveFieldsToDb] IPMI info of host ESX2.mycompany.com is not set

2012-08-21T11:45:35.855+10:00 [01228 info 'Default' opID=HB-host-7787@6001-20a8c164] [VpxdHostSync] Completed host synchronization for host-7787

2012-08-21T11:45:35.855+10:00 [01228 info 'Default' opID=HB-host-7787@6001-20a8c164] [VpxLRO] -- FINISH task-internal-110602 -- host-7787 -- VpxdInvtHostSyncHostLRO.Synchronize --

sa2057 · ‎08-21-2012

Hi,

Try restarting management network and reconfigure cluster.

Thanks

SA

TonyJK · ‎08-21-2012

Thanks for your advice.

I have disabled HA in the cluster but still getting "user root@127.0.0.1 logged in" every minute". Quite wired.

Cheers

sa2057 · ‎08-22-2012

Hi,

Try restarting VUM and vCenter services and also check this KB for disabling CIM agent which retrives information about Hardware health status

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

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

Thanks

SA

TonyJK · ‎08-22-2012

1) I have followed the KB to stop CIM (Hardware monitoring service on this host is not responding or not available).

2) I also stopped the "VMware vSphere Update Manager service" on the vCenter Server.

However, still get those logged in message !! Really don't know what is running in the background.

sa2057 · ‎08-23-2012

I guess it is the IBM CIM agent. can you find some infromation from IBM CIM agent logs?

Thanks

SA

TonyJK · ‎08-26-2012

Thanks for your advice. I will try and keep you posted.

Regards

CRad14 · ‎04-08-2013

Was this ever resolved?

Conrad www.vnoob.com | @vNoob | If I or anyone else is helpful to you make sure you mark their posts as such! 🙂

TBKing · ‎04-23-2013

I verified it was the HP Management Bundle - at least in my case.

Building new servers

VM updates - everything is fine

HP Mgmt Bundle 1.4.5-3

No logins before patch

1 minute logins after patch

Pretty annoying when you want to look for other issues or events.

Is there a way to turn down the logging level so root logins are not logged?

jglamann · ‎05-03-2013

We are experiencing similar issues in our environment. I have been updating all of our HP BL460 G8 blades to ESXi 5.1 U1 and in the process also updating the Management Bundle to 1.4.5-3. How I noticed a problem was we were getting constant entries of failures in the event log of the hosts. Message is "Cannot login user @127.0.0.1:no permission" This is with lockdown mode enabled. If I disabled lockdown mode then I still get entries in the log for log in and log out every minute or so. This is very annoying for troubleshooting purposes and needless to say is going to cause our vCenter DB to grow.

Does any one know of any updates to this issue? I have already updated six of our 40 + hosts and all six have this issue.

All

"User root@127.0.0.1 logged in" every minute ?