Unable to add host to vCenter as VPXA crashes with error: "Unable to allocate memory"

Products

• VMware vCenter Server

Issue/Introduction

Symptoms:

• Unable to add Host to vCenter.
• Post adding host to vCenter, Host gets disconnected quickly.
• Able to access the host directly.
• Resource pool named as "Resources"

 You will notice similar log snippet:

vpxa.log
2020-01-21T18:55:20.059Z verbose vpxa[9AF8B70] [Originator@6876 sub=PropertyProvider opID=HB-host-2353@98-5db5e015-17] [CommitChangesAndNotify] Updating cached values
2020-01-21T18:55:20.059Z info vpxa[9AF8B70] [Originator@6876 sub=vpxLro opID=HB-host-2353@98-5db5e015-17] [VpxLRO] -- BEGIN session[52a11219-2987-c288-b762-e8a44c42109d]52ff69f5-20ce-69ef-b99d-59247c2555d6 -- vpxa -- vpxapi.VpxaService.
retrieveChanges -- 52a11219-2987-c288-b762-e8a44c42109d
2020-01-21T18:55:20.059Z verbose vpxa[9AF8B70] [Originator@6876 sub=vpxaMoService opID=HB-host-2353@98-5db5e015-17] [GetChangesInt] Vpxa restarted or stolen by other server. Start a full sync
2020-01-21T18:55:20.059Z info vpxa[9AF8B70] [Originator@6876 sub=vpxaInvtHost opID=HB-host-2353@98-5db5e015-17] [VpxaInvtHost] ServerId has been changed from  0 to 299764
2020-01-21T18:55:20.059Z verbose vpxa[9AF8B70] [Originator@6876 sub=vpxaMoService opID=HB-host-2353@98-5db5e015-17] GetChanges: 0 -> 98
2020-01-21T18:55:20.088Z verbose vpxa[9AF8B70] [Originator@6876 sub=vpxaStatsMetadata opID=HB-host-2353@98-5db5e015-17] [VpxaStatsMetadata] Resetting counter translations (0, 0)
2020-01-21T18:55:20.088Z verbose vpxa[9AF8B70] [Originator@6876 sub=vpxaStatsMetadata opID=HB-host-2353@98-5db5e015-17] [VpxaStatsMetadata] Prior to refilling translations (0, 0)
2020-01-21T18:55:20.088Z verbose vpxa[9AF8B70] [Originator@6876 sub=vpxaStatsMetadata opID=HB-host-2353@98-5db5e015-17] [VpxaStatsMetadata] No new classes to consider

2020-01-21T18:55:20.108Z info vpxa[9B19B70] [Originator@6876 sub=vpxLro opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [VpxLRO] -- BEGIN lro-4 -- vpxa -- vpxapi.VpxaService.setConfig -- 52a11219-2987-c288-b762-e8a44c42109d
2020-01-21T18:55:20.108Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] Setting the VMOverheadGrowthLimit
2020-01-21T18:55:20.110Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] Mem.VMOverheadGrowthLimit already set to -1, ignoring
2020-01-21T18:55:20.110Z warning vpxa[9B19B70] [Originator@6876 sub=vpxaMoService opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [ProcessQuickStatsSpec] GetTranslators -- vpxd to host translation is empty
2020-01-21T18:55:20.110Z warning vpxa[9B19B70] [Originator@6876 sub=vpxaStatsMetadata opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [ProcessSpec] GetTranslators -- Failed to get translation.
2020-01-21T18:55:20.110Z verbose vpxa[9B19B70] [Originator@6876 sub=Alarm opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [ProcessAlarmSpec] Begin processing.
2020-01-21T18:55:20.110Z warning vpxa[9B19B70] [Originator@6876 sub=Alarm opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [ProcessAlarmSpec] GetTranslators -- vpxd to host translation is empty. Dropping results
2020-01-21T18:55:20.111Z verbose vpxa[9B19B70] [Originator@6876 sub=VpxaHalResourcePool opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] Starting to process resource notifications - new spec sync from vpxa
2020-01-21T18:55:20.111Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 SetResidual] _sourceMap.clear()
2020-01-21T18:55:20.111Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 SetResidual] before _sourceRoot init, _sourceMap = [0] {}
2020-01-21T18:55:20.111Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 TreeNode constructor] added mappping resgroup-8 -> vim.ResourcePool:resgroup-8
2020-01-21T18:55:20.111Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 TreeNode constructor] nodeMap = {'resgroup-8': '_id=resgroup-8:_name=Resources:_remoteMoRef=vim.ResourcePool:resgroup-8'}
2020-01-21T18:55:20.111Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 SetResidual] _sourceMap = [1] {'resgroup-8': '_id=resgroup-8:_name=Resources:_remoteMoRef=vim.ResourcePool:resgroup-8'}
2020-01-21T18:55:20.111Z verbose vpxa[9B19B70] [Originator@6876 sub=VpxaHalResourcePool opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [VpxaHostdSpecSync] Operation is transform ...
2020-01-21T18:55:20.120Z verbose vpxa[9B19B70] [Originator@6876 sub=VpxaHalResourcePool opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] FetchChildResourceSpec() done
.
2020-01-21T18:55:20.121Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 TreeNode constructor] added mappping resgroup-8 -> vim.ResourcePool:ha-root-pool
2020-01-21T18:55:20.121Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 TreeNode constructor] nodeMap = {'resgroup-8': '_id=resgroup-8:_name=Resources:_remoteMoRef=vim.ResourcePool:ha-root-pool'}
2020-01-21T18:55:20.121Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 TreeNode constructor] added mappping resgroup-8 -> vim.ResourcePool:pool0
2020-01-21T18:55:20.121Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 TreeNode constructor] nodeMap = {'resgroup-8': '_id=resgroup-8:_name=Resources:_remoteMoRef=vim.ResourcePoo
l:pool0'}
2020-01-21T18:55:20.121Z error vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] Unable to allocate memory
2020-01-21T18:55:20.121Z panic vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11]
-->
--> Panic: Unable to allocate memory
.
2020-01-21T18:55:20.121Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 TreeNode constructor] added mappping resgroup-8 -> vim.ResourcePool:pool0
2020-01-21T18:55:20.121Z verbose vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] [PR_629085 TreeNode constructor] nodeMap = {'resgroup-8': '_id=resgroup-8:_name=Resources:_remoteMoRef=vim.ResourcePool:pool0'}
2020-01-21T18:55:20.121Z error vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11] Unable to allocate memory
2020-01-21T18:55:20.121Z panic vpxa[9B19B70] [Originator@6876 sub=Default opID=HB-SpecSync-host-2353@0-4f8ab2c3-11]
-->
--> Panic: Unable to allocate memory
--> Backtrace:
--> [backtrace begin] product: VMware ESX, version: 6.5.0, build: build-15256549, tag: vpxa, cpu: x86, os: esx, buildType: release
--> backtrace[00] libvmacore.so[0x002E2C5F]: Vmacore::System::Stacktrace::CaptureFullWork(unsigned int)
--> backtrace[01] libvmacore.so[0x0012503E]: Vmacore::System::SystemFactoryImpl::CreateBacktrace(Vmacore::Ref<Vmacore::System::Backtrace>&)
--> backtrace[02] libvmacore.so[0x002DF820]
--> backtrace[03] libvmacore.so[0x002DF8D8]: Vmacore::PanicExit(char const*)
--> backtrace[04] libvmacore.so[0x000F3D82]
--> backtrace[05] libstdc++.so.6[0x00049D70]: operator new(unsigned int)
--> backtrace[06] vpxa[0x001DF7F6]
--> backtrace[07] vpxa[0x001DF8DF]
--> backtrace[08] vpxa[0x001E0BBA]
--> backtrace[09] vpxa[0x001E0FC0]
--> backtrace[10] vpxa[0x00258063]: VpxaHalResourcePoolImpl::GenerateTransformOperations(Vpxapi::ResourcePoolSpec*, Vpxapi::ResourcePoolSpec*, Vmacore::Ref<Vmomi::DataArray<Vpxapi::ResourcePoolChangeSpec> >&)
--> backtrace[11] vpxa[0x002548A3]
--> backtrace[12] vpxa[0x0025D381]
--> backtrace[13] vpxa[0x0025DDE1]
--> backtrace[14] vpxa[0x001FDF9A]
--> backtrace[15] vpxa[0x001AEBD3]
--> backtrace[16] vpxa[0x001B1802]
--> backtrace[17] vpxa[0x001B1887]
--> backtrace[18] libvpxapi-types.so[0x000897AA]
--> backtrace[19] libvmomi.so[0x000C2C37]
--> backtrace[20] libvmomi.so[0x000C51DA]
--> backtrace[21] vpxa[0x002914C0]
--> backtrace[22] vpxa[0x0015A88A]
--> backtrace[23] vpxa[0x00280D3B]: VpxLRO::PreAndBodyStartWork(VpxLRO*)
--> backtrace[24] vpxa[0x0027B933]: std::_Function_handler<void (), std::_Bind<void (*(VpxLRO*))(VpxLRO*)> >::_M_invoke(std::_Any_data const&)
--> backtrace[25] vpxa[0x001672C9]: std::function<void ()>::operator()() const
--> backtrace[26] vpxa[0x00280264]
--> backtrace[27] vpxa[0x00281EF5]: VpxLRO::LroMainEntry(VpxLRO*)
--> backtrace[28] vpxa[0x0027B8DB]: std::_Function_handler<bool (VpxLRO*), std::_Bind<bool (*(std::_Placeholder<1>))(VpxLRO*)> >::_M_invoke(std::_Any_data const&, VpxLRO*)
--> backtrace[29] vpxa[0x0027C05D]
--> backtrace[30] vpxa[0x0028776E]: VpxLroList::ThreadMainEntry()
--> backtrace[31] vpxa[0x0013958D]: std::_Function_handler<void (), void (*)()>::_M_invoke(std::_Any_data const&)
--> backtrace[32] vpxa[0x001672C9]: std::function<void ()>::operator()() const
--> backtrace[33] libvmacore.so[0x00209B13]
--> backtrace[34] libvmacore.so[0x00209F3E]
--> backtrace[35] libvmacore.so[0x0020E6E5]
--> backtrace[36] libvmacore.so[0x002EAA64]
--> backtrace[37] libpthread.so.0[0x00006CCA]
--> backtrace[38] libc.so.6[0x000D4C3E]
--> [backtrace end]

vpxd.log
2020-01-21T16:17:31.580Z info vpxd[7F628885D700] [Originator@6876 sub=HostCnx opID=CheckforMissingHeartbeats-10b1d72c] [VpxdHostCnx] No heartbeats received from host; cnx: 52f2d083-e814-16c8-36b1-d31d662dc100, h: host-10, time since last heartbeat: 994797ms
2020-01-21T16:17:31.580Z info vpxd[7F628885D700] [Originator@6876 sub=HostCnx opID=CheckforMissingHeartbeats-10b1d72c] [VpxdHostCnx] No heartbeats received from host; cnx: 52cbb96a-6c7d-640d-b465-1ab377813ae7, h: host-88, time since last heartbeat: 959010ms
2020-01-21T16:17:31.580Z info vpxd[7F628885D700] [Originator@6876 sub=HostCnx opID=CheckforMissingHeartbeats-10b1d72c] [VpxdHostCnx] No heartbeats received from host; cnx: 529282a0-75cc-27d5-1718-188425bbba64, h: host-40, time since last heartbeat: 826615ms
2020-01-21T16:18:31.585Z info vpxd[7F628885D700] [Originator@6876 sub=HostCnx opID=CheckforMissingHeartbeats-10b1d72c] [VpxdHostCnx] No heartbeats received from host; cnx: 529282a0-75cc-27d5-1718-188425bbba64, h: host-40, time since last heartbeat: 886620ms

2020-01-21T17:41:08.412Z warning vpxd[7F5176BF5700] [Originator@6876 sub=VpxProfiler opID=HB-SpecSync-host-2353@0-24e978b8] InvtSpecSyncLRO::StartWork [SpecSyncTime] took 50943 ms
2020-01-21T17:41:08.412Z info vpxd[7F5176BF5700] [Originator@6876 sub=vpxLro opID=HB-SpecSync-host-2353@0-24e978b8] [VpxLRO] -- FINISH lro-1850
2020-01-21T17:41:08.412Z error vpxd[7F51FD99B700] [Originator@6876 sub=vmomi.soapStub[88]] Resetting stub adapter for server <cs p:00007f51882bad40, TCP:myhost.local:443> : service state request failed: N7Vmacore4Http24MalformedHeaderExceptionE(Server closed connection after 0 response bytes read; <SSL(<io_obj p:0x00007f51c8238450, h:40, <TCP 'x.x.x.x:46880'>, <TCP 'x.x.x.x:443'>>)>)
--> [context]zKq7AVECAAAAAJlh4gAPdnB4ZAAA4LArbGlidm1hY29yZS5zbwAAwhcbAB5aGABMNRwAb5sdADWeHQAoLx4AMn0aAPBJJgAKMSQAI/wjAAr/IwCXCSwB1HMAbGlicHRocmVhZC5zby4wAALdjg5saWJjLnNvLjYA[/context]
2020-01-21T17:41:08.412Z error vpxd[7F51F6FB7700] [Originator@6876 sub=Vmomi opID=HB-host-2353@97-7a60654-TaskLoop-5bf48af6] Got vmacore exception: N7Vmacore4Http24MalformedHeaderExceptionE(Server closed connection after 0 response bytes read; <SSL(<io_obj p:0x00007f51b0264df0, h:50, <TCP 'x.x.x.x:46884'>, <TCP 'x.x.x.x:443'>>)>)
--> [context]zKq7AVECAAAAAJlh4gAPdnB4ZAAA4LArbGlidm1hY29yZS5zbwAAwhcbAB5aGABMNRwAb5sdADWeHQAoLx4AMn0aAPBJJgAKMSQAI/wjAAr/IwCXCSwB1HMAbGlicHRocmVhZC5zby4wAALdjg5saWJjLnNvLjYA[/context]
2020-01-21T17:41:08.414Z warning vpxd[7F51F6FB7700] [Originator@6876 sub=VpxProfiler opID=HB-host-2353@97-7a60654-TaskLoop-5bf48af6] TaskLoop [TotalTime] took 50944 ms
2020-01-21T17:41:08.426Z warning vpxd[7F51F7FFF700] [Originator@6876 sub=Default opID=HB-host-2353@97-7a60654] Closing Response processing in unexpected state: 3
2020-01-21T17:41:08.426Z error vpxd[7F51F7FFF700] [Originator@6876 sub=Vmomi opID=HB-host-2353@97-7a60654] Got vmacore exception: N7Vmacore4Http13HttpExceptionE(HTTP error response: Service Unavailable)

2020-01-21T17:41:08.428Z warning vpxd[7F51F7FFF700] [Originator@6876 sub=InvtHostCnx opID=HB-host-2353@97-7a60654] Exception occurred during host sync; Host communication failed; [vim.HostSystem:host-2353,atsgp1pod1-esx2.airtrunksgp1.local], e: N5Vmomi5Fault17HostCommunication9ExceptionE(vmodl.fault.HostCommunication)
--> [context]zKq7AVECAAAAAJlh4gATdnB4ZAAA4LArbGlidm1hY29yZS5zbwAAwhcbAB5aGAGiPhlsaWJ2bW9taS5zbwABCkUZAqqHdHZweGQAAh6LdAIpOXoCf2J6AoysegLTDnQCSAR0Av8odAJAfHQAI/wjAAr/IwCXCSwD1HMAbGlicHRocmVhZC5zby4wAATdjg5saWJjLnNvLjYA[/context]
2020-01-21T17:41:08.432Z warning vpxd[7F51F7FFF700] [Originator@6876 sub=VpxProfiler opID=HB-host-2353@97-7a60654] InvtHostSyncLRO::StartWork [HostSyncTime] took 50964 ms
2020-01-21T17:41:08.528Z info vpxd[7F51F71B8700] [Originator@6876 sub=vpxLro opID=517c75ce-b211-4bcf-ad75-d12b6315829e-17749-ngc-ad] [VpxLRO] -- FINISH lro-1856
2020-01-21T17:41:09.530Z info vpxd[7F51FC591700] [Originator@6876 sub=vpxLro opID=517c75ce-b211-4bcf-ad75-d12b6315829e-17777-ngc-c3] [VpxLRO] -- BEGIN lro-1860 -- ChangeLogCollector -- vim.cdc.ChangeLogCollector.waitForChanges -- 52977aea-9d8b-bfb0-236d-643e1c78a220(52ece893-ae69-565a-2eba-362bdf6392b3)
2020-01-21T17:41:19.600Z info vpxd[7F51751E8700] [Originator@6876 sub=InvtHostCnx opID=HeartbeatStartHandler-10b1d72c] [VpxdHeartbeat] Need full sync for: host-2353
2020-01-21T17:41:19.601Z info vpxd[7F51EDDEE700] [Originator@6876 sub=vpxLro opID=HB-SpecSync-host-2353@0-67f7aac1] [VpxLRO] -- BEGIN lro-1862 --  -- SpecSyncLRO.Synchronize --
2020-01-21T17:41:19.641Z info vpxd[7F51F55AA700] [Originator@6876 sub=Vmomi opID=HB-host-2353@97-72ff8eca] [ClientAdapterBase] Retry SOAP call after exception; host: myhost.local, method: vpxapi.VpxaService.retrieveChanges, exception: N6Vpxapi5Fault16NotAuthenticated9ExceptionE('vpxapi.fault.NotAuthenticated'

Environment

VMware vCenter Server Appliance 6.5.x
VMware vCenter Server 6.5.x

Cause

By default, VPXA uses "Resources"(ha-root-pool) as the root resource pool and it is suggested not to assign the same name to user resource pools.

Resolution

To resolve this issue:

1. Disconnect the host and remove from vCenter inventory.
2. Stop vpxa.
3. Rename the user created 'Resources' resource pool via vCenter as some different name.
4. SSH to ESXi host and take backup of pools.xml in /tmp location.
5. Remove the pools.xml file. (rm -f /etc/vmware/hostd/pools.xml)
6. Restart vpxa.
7. Add the host back to vCenter.