Unable to remediate Host due to Error while waiting for untar process

Products

VMware vSphere ESXi

Issue/Introduction

ESXi hosts booting from SD card (Note: SD Card revised guidance) may experience single image managed cluster remediation failures.
Remediation of cluster failed with below error
Remediation failed for Host : <esxi_hostname>
<esxi_hostname> - Failed to remediate host

Lifecycle log file on the ESXi will show errors similar to below snippets :

/var/run/log/lifecycle.log

Er(11) lifecycle[2119667]: imagemanagerctl:96 [InstallationError]
Er(11)[+] lifecycle[2119667]: VMware_locker_tools-light_12.3.5.22544099-23305545: Error while waiting for untar process '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']': Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2119711'.
Er(11) lifecycle[2119667]: imagemanagerctl:101 Traceback (most recent call last):
Er(11) lifecycle[2119667]: imagemanagerctl:101 File "/tmp/esx-update-2119667/lib64/python3.8/site-packages/vmware/esximage/Installer/LockerInstaller.py", line 107, in close
Er(11) lifecycle[2119667]: imagemanagerctl:101 File "/lib64/python3.8/site-packages/vmware/runcommand.py", line 290, in waitProcessToComplete
Er(11) lifecycle[2119667]: imagemanagerctl:101 vmware.runcommand.RunCommandError: Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2119711'.
Er(11) lifecycle[2119667]: imagemanagerctl:101
Er(11) lifecycle[2119667]: imagemanagerctl:101 During handling of the above exception, another exception occurred:
Er(11) lifecycle[2119667]: imagemanagerctl:101
Er(11) lifecycle[2119667]: imagemanagerctl:101 Traceback (most recent call last):
Er(11) lifecycle[2119667]: imagemanagerctl:101 File "/tmp/esx-update-2119667/lib64/python3.8/site-packages/vmware/esximage/HostImage.py", line 947, in _download_and_stage
Er(11) lifecycle[2119667]: imagemanagerctl:101 File "/tmp/esx-update-2119667/lib64/python3.8/site-packages/vmware/esximage/HostImage.py", line 816, in _verify_and_write_payload
Er(11) lifecycle[2119667]: imagemanagerctl:101 File "/tmp/esx-update-2119667/lib64/python3.8/site-packages/vmware/esximage/Installer/LockerInstaller.py", line 112, in close
Er(11) lifecycle[2119667]: imagemanagerctl:101 esximage.Errors.InstallationError: Error while waiting for untar process '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']': Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2119711'.

In case of a baseline cluster, using pre-defined baselines, below would be the error message and respective log snippets:
During Install, it would error out with : "An error occurred during host configuration".
Log snippets in vCenter's var/log/vmware/vum-server/vmware-vum-server.log

yyyy-mm-ddT info vmware-vum-server[09945] [Originator@6876 sub=VciRemediateTask.RemediateTask{603}] [vciTask
Base 1372] SerializeToVimFault fault:
--> (integrity.fault.VcIntegrityFault) {
--> faultCause = (vmodl.MethodFault) null,
--> faultMessage = <unset>
--> msg = "Install error on host: , error details: Platform Configuration Error: /usr/sbin/esxupdate returned with exit status: 15"
--> }
--> Converted fault:
--> (vim.fault.ExtendedFault) {
--> faultCause = (vmodl.MethodFault) null,
--> faultMessage = <unset>,
--> faultTypeId = "com.vmware.vcIntegrity.VcIntegrityFault",
--> data = (vim.KeyValue) [
--> (vim.KeyValue) {
--> key = "faultCause",
--> value = ""
--> },
--> (vim.KeyValue) {
--> key = "faultMessage",
--> value = ""
--> }
--> ]
--> msg = "Install error on host: , error details: Platform Configuration Error: /usr/sbin/esxupdate returned with exit status: 15"
--> }

Log snippets in ESXi hosts var/run/log/hostd.log shows

yyyy-mm-ddT info hostd[2100677] [Originator@6876 sub=Hostsvc.VmkVprobSource] VmkVprobSource::Post event: (vim.event.EventEx) {
--> key = 58,
--> chainId = 1025431560,
--> createdTime = "",
--> userName = "",
--> host = (vim.event.HostEventArgument) {
--> name = "",
--> host = 'vim.HostSystem:ha-host'
--> },
--> eventTypeId = "esx.problem.esximage.install.stage.error",
--> arguments = (vmodl.KeyAnyValue) [
--> (vmodl.KeyAnyValue) {
--> key = "1",
--> value = "(Updated) Cisco-UCS-Custom-ESXi-7-15843807_4.1.1-a"
--> },
--> (vmodl.KeyAnyValue) {
--> key = "2",
--> value = "VMware_locker_tools-light_12.3.5.22544099-23794019: Error while waiting for untar process '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']': Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2171551'."
--> }
--> ],
--> objectId = "ha-host",
--> objectType = "vim.HostSystem",
--> }
yyyy-mm-ddTinfo hostd[2100677] [Originator@6876 sub=Vimsvc.ha-eventmgr] Event 7601 : Could not stage image profile '(Updated) <OEM image>': VMware_locker_tools-light_12.3.5.22544099-23794019: Error while waiting for untar process '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']': Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2171551'.

Log snippets ESXi host var/run/log/esxupdate.log:

yyyy-mm-ddT esxupdate: 2171510: vmware.runcommand: INFO: runcommand called with: args = '['/usr/lib/vmware/vob/bin/addvob', 'vob.user.esximage.install.stage.error', '(Updated) OEM image', "VMware_locker_tools-light_12.3.5.22544099-23794019: Error while waiting for untar process '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']': Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2171551'."]', outfile = 'None', returnoutput = 'True', timeout = '0.0'.
yyyy-mm-ddT esxupdate: 2171510: esxupdate: ERROR: esximage.Errors.InstallationError: Error while waiting for untar process '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']': Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2171551'.
yyyy-mm-ddT esxupdate: 2171510: esxupdate: ERROR: esximage.Errors.InstallationError: VMware_locker_tools-light_12.3.5.22544099-23794019: Error while waiting for untar process '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']': Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2171551'.
yyyy-mm-ddT esxupdate: 2139653: esxupdate: ERROR: esximage.Errors.InstallationError: Error while waiting for untar process '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']': Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2139687'.
yyyy-mm-ddT1 esxupdate: 2139653: esxupdate: ERROR: esximage.Errors.InstallationError: VMware_locker_tools-light_12.3.5.22544099-23794019: Error while waiting for untar process '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']': Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2139687'.
yyyy-mm-ddT esxupdate: 2139653: vmware.runcommand: INFO: runcommand called with: args = '['/usr/lib/vmware/vob/bin/addvob', 'vob.user.esximage.install.stage.error', '(Updated) <OEM image>', "VMware_locker_tools-light_12.3.5.22544099-23794019: Error while waiting for untar process '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']': Timeout (30 seconds) expired waiting for output from command '['/bin/tar', 'xzf', '-', '-C', '/locker/packages/']', pid '2139687'."]', outfile = 'None', returnoutput = 'True', timeout = '0.0'.

Environment

ESXi 7.x
ESXi 8.x

Cause

This issue is caused when untar operation of individual VIBs takes more than the default 30 seconds timeout during the remediation process. For environments using SD card as the OSData partition, there are chances that VMware tools untar process takes slightly higher duration.

Resolution

These issues can be due to USB/SD-cards which are old or have gone through higher read/writes or have bad sectors

If this issue is faced, reach out to the USB/SD-card vendor and run a hardware diagnostics.
Collect the SD card health and how many read/write cycles has it gone through.
Check if there are bad sectors.

If there are issues detected during the hardware diagnostics, then replace the SD-card/USB or preferably plan to setup OS-Data partition on a persistent location as per recommendations given in - SD card/USB boot device revised guidance

The timeout is increased to 120 secs from 30 secs for the VMware-VM-Tools component in below releases.

ESXi 7.0 U3v release. Log in to the Broadcom Support Portal to download this patch
ESXi 8.0 U3b release. Log in to the Broadcom Support Portal to download this patch

Workarounds

Workaround 1:

Step 1: Manually increase the timeout of the untar process:

Note:

These steps are non-persistent and will revert back to default after the host undergoes reboot.

The "Step 1" procedure is necessary to avoid a timeout error during the manual upgrade in "Step 2".

Login to ESXi host using SSH
Execute below vsish command to allow file modification

vsish -e set /config/VisorFS/intOpts/VisorFSPristineTardisk 0
Take backup of file /lib64/python3.8/site-packages/vmware/esximage/Installer/LockerInstaller.py

cp /lib64/python3.8/site-packages/vmware/esximage/Installer/LockerInstaller.py /tmp/LockerInstaller.py
Take another backup of the file copied in /tmp before editing it

cp /tmp/LockerInstaller.py /tmp/LockerInstaller.py.bak
Change permission of file /tmp/LockerInstaller.py

chmod 777 /tmp/LockerInstaller.py
Edit the file /tmp/LockerInstaller.py to increase the timeout from 30 to 120 seconds

vi /tmp/LockerInstaller.py

Change value of timeout to 120

def close(self, timeout=30): <<<<<< make this value 120
'''Close untar stream and wait for process completion.
Parameters:
* timeout - the amount of time in seconds, to wait for output
or completion of the process.
'''

After modification:

def close(self, timeout=120):
'''Close untar stream and wait for process completion.
Parameters:
* timeout - the amount of time in seconds, to wait for output
or completion of the process.
'''

Save the changes and exit 'vi' editor using !wq
Move /tmp/LockerInstaller.py to /lib64/python3.8/site-packages/vmware/esximage/Installer/LockerInstaller.py and overwrite it.

mv /tmp/LockerInstaller.py /lib64/python3.8/site-packages/vmware/esximage/Installer/LockerInstaller.py
Execute below vsish command to default value to disable file modifications

vsish -e set /config/VisorFS/intOpts/VisorFSPristineTardisk 1

Step 2: For VLCM, manually upgrade VMware Tools that is in the version mentioned in the vLCM Image desired state.

Download the desired state ESXi zipped bundle from Broadcom Download Portal and upload to a datastore.

Note: The complete version of VMware Tools can be found from the logs (Installation Error message)
Upgrade VMware Tools using esxcli command

esxcli software component apply -n VMware-VM-Tools -d /<path>/VMware-ESXi-X.0-XXXXXXXX-depot.zip

Step 3: Proceed Remediation

Login to vCenter Server UI and select Lifecycle Manager
Check the Cluster Compliance and execute the remediation.

Workaround 2:

Step 1: Create a new baseline or modify the existing baseline or image with a newer VMware Tools package (eg 12.4.x or newer)

Step 2: Proceed Remediation

Login to vCenter Server UI and select Lifecycle Manager
Check the Cluster Compliance and execute the remediation.