"Exception occurred in postInstallHook" error when patching the vCenter Server

Products

• VMware vCenter Server

Issue/Introduction

• Patching the vCenter Server fails with the below error message on the vCenter Appliance Management Interface:
  
  "Exception occurred in postInstallHook for B2B-patching. Please check the logs for more details. Take corrective action and then resume."



• On the vCenter Server, in /var/log/vmware/vmon/vmon.log, there are 'connection refused' errors while performing a health check against the imagebuilder service:

YYYY-MM-DDTYY:MM:SSZ In(05) host-#### <imagebuilder> Running the API Health command as user imagebuilder
YYYY-MM-DDTYY:MM:SSZ In(05) host-#### <imagebuilder-healthcmd> Constructed command: /usr/bin/python /usr/lib/vmware-vmon/vmonApiHealthCmd.py -n imagebuilder -u /vmw/imagebuilder/httpd/healthstatus -t 30
YYYY-MM-DDTYY:MM:SSZ Wa(03) host-#### <imagebuilder> Service api-health command's stderr: Exception while retrieving health xml from url http://localhost:8099/vmw/imagebuilder/httpd/healthstatus. Exception: <urlopen error [Errno 111] Connection refused>

• After 240 seconds, the vmon service terminates the imagebuilder service startup task, deeming it unresponsive:

YYYY-MM-DDTYY:MM:SSZ In(05) host-#### <imagebuilder> Running the API Health command as user imagebuilder
YYYY-MM-DDTYY:MM:SSZ In(05) host-#### <imagebuilder-healthcmd> Constructed command: /usr/bin/python /usr/lib/vmware-vmon/vmonApiHealthCmd.py -n imagebuilder -u /vmw/imagebuilder/httpd/healthstatus -t 30
YYYY-MM-DDTYY:MM:SSZ In(05) host-#### <imagebuilder> Service start operation timed out.
YYYY-MM-DDTYY:MM:SSZ In(05) host-#### <imagebuilder-healthcmd> Cancelling execution of pid ####
YYYY-MM-DDTYY:MM:SSZ Wa(03) host-#### <imagebuilder> Found empty StopSignal parameter in config file. Defaulting to SIGTERM

• The /var/log/vmware/applmgmt/PatchRunner.log shows the below error:

YYYY-MM-DDTYY:MM:SSZ ERROR vmware_b2b.patching.phases.patcher Patch hook Patch got unhandled exception.
Traceback (most recent call last):
  File "/storage/core/software-packages/scripts/patches/py/vmware_b2b/patching/phases/patcher.py", line 203, in patch
    _patchComponents(ctx, userData, statusAggregator.reportingQueue)
  File "/storage/core/software-packages/scripts/patches/py/vmware_b2b/patching/phases/patcher.py", line 84, in _patchComponents
    _startDependentServices(c)
  File "/storage/core/software-packages/scripts/patches/py/vmware_b2b/patching/phases/patcher.py", line 53, in _startDependentServices
    serviceManager.start(depService)
  File "/storage/core/software-packages/scripts/patches/libs/sdk/service_manager.py", line 901, in wrapper
    return getattr(controller, attr)(*args, **kwargs)
  File "/storage/core/software-packages/scripts/patches/libs/sdk/service_manager.py", line 794, in start
    super(VMwareServiceController, self).start(serviceName)
  File "/storage/core/software-packages/scripts/patches/libs/sdk/service_manager.py", line 665, in start
    raise IllegalServiceOperation(errorText)
service_manager.IllegalServiceOperation: Service cannot be started. Error: Error executing start on service imagebuilder. Details {
    "detail": [
        {
            "id": "install.ciscommon.service.failstart",
            "translatable": "An error occurred while starting service '%(0)s'",
            "args": [
                "imagebuilder"
            ],
            "localized": "An error occurred while starting service 'imagebuilder'"

• Increasing the time-outs as outlined in the following KB does not resolve the issue:  vCenter Server upgrade from 7.0 U2 to 7.0 U3c fails with error "Exception occured in postInstallHook"  

• There are a large number of entries in the vCenter Server database event tables that can be identified using  Determining where growth is occurring in the vCenter Server database under the section "Verifying vPostgres embedded database".
• There may be signs of slow database queries in the /var/log/vmware/vpxd/vpxd.log 

YYYY-MM-DDTYY:MM:SSZ warning vpxd[#####] [Originator@#### sub=Default opID=########] [VdbStatement] SQL execution took too long:  SELECT EVENT_ID, CHAIN_ID, EVENT_TYPE, EXTENDED_CLASS, CREATE_TIME, USERNAME, CATEGORY, VM_ID,VM_NAME, HOST_ID, HOST_NAME, COMPUTERESOURCE_ID, COMPUTERESOURCE_TYPE,COMPUTERESOURCE_NAME, DATACENTER_ID, DATACENTER_NAME, DATASTORE_ID, DATASTORE_NAME, NETWORK_ID, NETWORK_NAME, NETWORK_TYPE, DVS_ID, DVS_NAME, STORAGEPOD_ID, STORAGEPOD_NAME, CHANGE_TAG_ID FROM VPXV_EVENT_ALL  WHERE CREATE_TIME>=? AND EVENT_ID<? ORDER BY EVENT_ID DESC LIMIT 10;

Environment

VMware vCenter Server 7.x

VMware vCenter Server 8.x

Cause

• This issue can occur if there are a large number of entries in some tables in the vCenter Server database e.g. vpxv_event_all.
• If there are slow queries serialized on these tables after the vpxd service starts, it can block the updateExtension request for the imagebuilder service.
• This causes the service startup failure and results in the patch failure.

Resolution

This is a known issue and currently there is no resolution.

Workaround:

• Based on the database size and the tables involved, a clean up of the database will be required.
• If the table impacted is the VPXV_EVENT_ALL, as per the example above, please refer  /storage/seat disk 100% full on vCenter Server Appliance 6.x/7.x/8.x
• If there are other tables impacted, please contact VMware Support. For more information, see Creating and managing Broadcom support cases

Additional Information

Note: The above issue can be encountered for vmware-updatemgr and vmware-vsan-health services. The same plan of action is applicable for them.