VMware Update Manager reports "error code 99" during scan operation
After updating my lab to VMware vSphere 6.0 U2, one of my hosts continuously thrown an error during an update scan.
Host returns ESX error code 99, unhandled exception has occurred
The first thing I’ve checked was the esxupdate.log on the affected ESXi host. This is the output, that was logged during a scan operation.
2016-04-04T13:42:13Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/sbin/esxcfg-advcfg', '-q', '-g', '/UserVars/EsximageNetTimeout']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.
2016-04-04T13:42:14Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/sbin/esxcfg-advcfg', '-q', '-g', '/UserVars/EsximageNetRetries']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.
2016-04-04T13:42:14Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/sbin/esxcfg-advcfg', '-q', '-g', '/UserVars/EsximageNetRateLimit']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.
2016-04-04T13:42:14Z esxupdate: esxupdate: INFO: ---
Command: scan
Args: ['scan']
Options: {'nosigcheck': None, 'retry': 5, 'loglevel': None, 'cleancache': None, 'viburls': None, 'meta': ['http://vum.lab.local:9084/vum/repository/hostupdate/10960002/metadata_1456989617.zip', 'http://vum.lab.local:9084/vum/repository/hostupdate/vmw/vmw-ESXi-6.0.0-metadata.zip'], 'proxyurl': None, 'timeout': 30.0, 'cachesize': None, 'hamode': True, 'maintenancemode': None}
2016-04-04T13:42:14Z esxupdate: BootBankInstaller.pyc: DEBUG: Creating an empty ImageProfile for bootbank /bootbank
2016-04-04T13:42:14Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/sbin/bootOption', '-rp']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.
2016-04-04T13:42:14Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/sbin/bootOption', '-ro']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.
2016-04-04T13:42:14Z esxupdate: downloader: DEBUG: Downloading http://vum.lab.local:9084/vum/repository/hostupdate/10960002/metadata_1456989617.zip to /tmp/tmpWW6WJC...
2016-04-04T13:42:17Z esxupdate: Metadata.pyc: INFO: Unrecognized file vendor-index.xml in Metadata file
2016-04-04T13:42:17Z esxupdate: downloader: DEBUG: Downloading http://vum.lab.local:9084/vum/repository/hostupdate/vmw/vmw-ESXi-6.0.0-metadata.zip to /tmp/tmpKfdI64...
2016-04-04T13:42:20Z esxupdate: Metadata.pyc: INFO: Unrecognized file vendor-index.xml in Metadata file
2016-04-04T13:42:21Z esxupdate: BootBankInstaller.pyc: DEBUG: Creating an empty ImageProfile for bootbank /bootbank
2016-04-04T13:42:22Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/usr/sbin/vsish', '-e', '-p', 'cat', '/hardware/bios/dmiInfo']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.
2016-04-04T13:42:22Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/sbin/smbiosDump']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.
2016-04-04T13:42:22Z esxupdate: BootBankInstaller.pyc: DEBUG: Creating an empty ImageProfile for bootbank /bootbank
2016-04-04T13:42:22Z esxupdate: BootBankInstaller.pyc: DEBUG: Creating an empty ImageProfile for bootbank /bootbank
2016-04-04T13:42:23Z esxupdate: BootBankInstaller.pyc: DEBUG: Creating an empty ImageProfile for bootbank /bootbank
2016-04-04T13:42:23Z esxupdate: Transaction: DEBUG: Populating VIB list from all VIBs in metadata http://vum.lab.local:9084/vum/repository/hostupdate/10960002/metadata_1456989617.zip; depots:
2016-04-04T13:42:23Z esxupdate: downloader: DEBUG: Downloading http://vum.lab.local:9084/vum/repository/hostupdate/10960002/metadata_1456989617.zip to /tmp/tmpFQrdX3...
2016-04-04T13:42:23Z esxupdate: Metadata.pyc: INFO: Unrecognized file vendor-index.xml in Metadata file
2016-04-04T13:42:23Z esxupdate: Transaction: DEBUG: Populating VIB list from all VIBs in metadata http://vum.lab.local:9084/vum/repository/hostupdate/vmw/vmw-ESXi-6.0.0-metadata.zip; depots:
2016-04-04T13:42:23Z esxupdate: downloader: DEBUG: Downloading http://vum.lab.local:9084/vum/repository/hostupdate/vmw/vmw-ESXi-6.0.0-metadata.zip to /tmp/tmplZxgm6...
2016-04-04T13:42:23Z esxupdate: Metadata.pyc: INFO: Unrecognized file vendor-index.xml in Metadata file
2016-04-04T13:42:24Z esxupdate: esxupdate: ERROR: An unexpected exception was caught:
2016-04-04T13:42:24Z esxupdate: esxupdate: ERROR: Traceback (most recent call last):
2016-04-04T13:42:24Z esxupdate: esxupdate: ERROR: File "/usr/sbin/esxupdate", line 238, in main
2016-04-04T13:42:24Z esxupdate: esxupdate: ERROR: cmd.Run()
2016-04-04T13:42:24Z esxupdate: esxupdate: ERROR: File "/build/mts/release/bora-3620759/bora/build/esx/release/vmvisor/sys-boot/lib/python2.7/site-packages/vmware/esx5update/Cmdline.py", line 113, in Run
2016-04-04T13:42:24Z esxupdate: esxupdate: ERROR: File "/build/mts/release/bora-3620759/bora/build/esx/release/vmvisor/sys-boot/lib/python2.7/site-packages/vmware/esx5update/MetadataScanner.py", line 244, in Scan
2016-04-04T13:42:24Z esxupdate: esxupdate: ERROR: File "/build/mts/release/bora-3620759/bora/build/esx/release/vmvisor/sys-boot/lib/python2.7/site-packages/vmware/esx5update/MetadataScanner.py", line 106, in _generateOperationData
2016-04-04T13:42:24Z esxupdate: esxupdate: ERROR: File "/build/mts/release/bora-3620759/bora/build/esx/release/vmvisor/sys-boot/lib/python2.7/site-packages/vmware/esx5update/MetadataScanner.py", line 88, in _getInstallProfile
2016-04-04T13:42:24Z esxupdate: esxupdate: ERROR: AttributeError: 'NoneType' object has no attribute 'Copy'
2016-04-04T13:42:24Z esxupdate: esxupdate: DEBUG: <<<
You might notice the “Unrecognized file vendor-index.xml in Metadata file” error. I also found this error message on the other hosts, so I excluded it from further research. It was unlikely, that this error was related to the observed problem. I started searching differences between the hosts and found out, that the output of “esxcli software vib list” was different on the faulty host.
This is the output on the faulty host:
[root@esx1:~] esxcli software vib list
Name Version Vendor Acceptance Level Install Date
----------- ------------------ ------ ---------------- ------------
tools-light 6.0.0-2.34.3620759 VMware VMwareCertified 2016-04-04
[root@esx1:~]
This is the output on a working host. You see the difference?
[root@esx2:~] esxcli software vib list
Name Version Vendor Acceptance Level Install Date
----------------------------- ------------------------------------- --------------- ---------------- ------------
net-tg3 3.137l.v60.1-1OEM.600.0.0.2494585 BRCM VMwareCertified 2016-03-03
elxnet 10.5.121.7-1OEM.600.0.0.2159203 EMU VMwareCertified 2016-03-03
ima-be2iscsi 10.5.101.0-1OEM.600.0.0.2159203 EMU VMwareCertified 2016-03-03
lpfc 10.5.70.0-1OEM.600.0.0.2159203 EMU VMwareCertified 2016-03-03
scsi-be2iscsi 10.5.101.0-1OEM.600.0.0.2159203 EMU VMwareCertified 2016-03-03
scsi-lpfc820 8.2.4.157.70-1OEM.500.0.0.472560 Emulex VMwareCertified 2016-03-03
hpe-build 600.9.4.5.11-2494585 HPE PartnerSupported 2016-03-03
char-hpcru 6.0.6.14-1OEM.600.0.0.2159203 Hewlett-Packard PartnerSupported 2016-03-03
...
...
...
tools-light 6.0.0-2.34.3620759 VMware VMwareCertified 2016-04-04
scsi-qla2xxx 934.5.20.0-1OEM.500.0.0.472560 qlogic VMwareCertified 2016-03-03
[root@esx2:~]
Doesn’t look right… I investigated further, still searching for differences. And then I found two empty directories under /var/db/esximg.
[root@esx1:~] ls -l /var/db/esximg/*
/var/db/esximg/profiles:
total 0
/var/db/esximg/vibs:
total 0
[root@esx1:~]
The same directory was populated on other, working hosts.
[root@esx2:~] ls -l /var/db/esximg/*
/var/db/esximg/profiles:
total 20
-r--r--r-- 1 root root 20238 Apr 4 11:23 %28Updated%29%20HPE-ESXi-6.0.0-Update1-iso-600.9.41594098800
/var/db/esximg/vibs:
total 732
-r--r--r-- 1 root root 1704 Apr 4 11:23 ata-pata-amd--1600059064.xml
-r--r--r-- 1 root root 1728 Apr 4 11:23 ata-pata-atiixp--1227646244.xml
-r--r--r-- 1 root root 1719 Apr 4 11:23 ata-pata-cmd64x-782653683.xml
-r--r--r-- 1 root root 1748 Apr 4 11:23 ata-pata-hpt3x2n-852032191.xml
-r--r--r-- 1 root root 1730 Apr 4 11:23 ata-pata-pdc2027x-236283737.xml
...
...
...
-r--r--r-- 1 root root 16416 Apr 4 11:23 vsanhealth--1252089272.xml
-r--r--r-- 1 root root 1726 Apr 4 11:23 xhci-xhci-1668869473.xml
[root@esx2:~]
One possible solution was therefore to copy the missing files to the faulty host. I used SCP for this. To get SCP working, you have to enable the SSH Client in the ESXi firewall.
[root@esx2:/var/db] esxcli network firewall ruleset set --enabled true --ruleset-id=sshClient
After that, I’ve copied the files from a working host to the faulty host. Please make sure that the hosts have the same build! In my case, both hosts had the same build. Don’t try to copy files from an older or newer build to the host!!
[root@esx2:/var/db] scp -r esximg/ root@esx1:/var/db
The authenticity of host 'esx1 (192.168.200.33)' can't be established.
RSA key fingerprint is SHA256:OSzz9Kk4QDRtmj7ed2J+1qcniIhBVJuJVEKf/4+Gry4.
Are you sure you want to continue connecting (yes/no)? yes
Warning: Permanently added 'esx1,192.168.200.33' (RSA) to the list of known hosts.
Password:
sata-sata-sil-1748273158.xml 100% 1717 1.7KB/s 00:00
lsi-mr3-989864457.xml 100% 1751 1.7KB/s 00:00
scsi-ips--1979861494.xml 100% 1619 1.6KB/s 00:00
char-hpcru--1874046437.xml 100% 1638 1.6KB/s 00:00
scsi-lpfc820--634308064.xml 100% 1663 1.6KB/s 00:00
net-tg3--917722591.xml 100% 1707 1.7KB/s 00:00
ipmi-ipmi-devintf-1862766627.xml 100% 1719 1.7KB/s 00:00
...
...
...
scsi-aic79xx-757558775.xml 100% 1643 1.6KB/s 00:00
hp-ams-1212738556.xml 100% 2035 2.0KB/s 00:00
%28Updated%29%20HPE-ESXi-6.0.0-Update1-iso-600.9.41594098800 100% 20KB 19.8KB/s 00:00
[root@esx2:/var/db]
And because we are pros, we disable the SSH Client after using it.
[root@esx2:/var/db] esxcli network firewall ruleset set --enabled false --ruleset-id=sshClient
As expected, “esxcli software vib list” was working again.
[root@esx1:~] esxcli software vib list
Name Version Vendor Acceptance Level Install Date
----------------------------- ------------------------------------- --------------- ---------------- ------------
net-tg3 3.137l.v60.1-1OEM.600.0.0.2494585 BRCM VMwareCertified 2016-03-03
elxnet 10.5.121.7-1OEM.600.0.0.2159203 EMU VMwareCertified 2016-03-03
ima-be2iscsi 10.5.101.0-1OEM.600.0.0.2159203 EMU VMwareCertified 2016-03-03
lpfc 10.5.70.0-1OEM.600.0.0.2159203 EMU VMwareCertified 2016-03-03
scsi-be2iscsi 10.5.101.0-1OEM.600.0.0.2159203 EMU VMwareCertified 2016-03-03
scsi-lpfc820 8.2.4.157.70-1OEM.500.0.0.472560 Emulex VMwareCertified 2016-03-03
hpe-build 600.9.4.5.11-2494585 HPE PartnerSupported 2016-03-03
char-hpcru 6.0.6.14-1OEM.600.0.0.2159203 Hewlett-Packard PartnerSupported 2016-03-03
...
...
...
tools-light 6.0.0-2.34.3620759 VMware VMwareCertified 2016-04-04
scsi-qla2xxx 934.5.20.0-1OEM.500.0.0.472560 qlogic VMwareCertified 2016-03-03
[root@esx1:~]
A rescan operation in the vSphere Client was also successful. It seems that the root cause for the problem were missing files under /var/db/esximg.
Please don’t ask why this has happened. I really have no idea. But VMware KB2043170 (Initializing the VMware vCenter Update Manager database without reinstalling it) isn’t always the solution for “error code 99”, as sometimes written somewhere in the internet. Always try to analyze the problem and try to filter out unlikely and likely solutions.