That… Could Be A Problem…

8Dec/115

VMware Update Manager: Error Code 7

After updating from vSphere 4 to vSphere 5 (both hosts and vCenter) in our production environment, I happened to run into a problem with VMware's Update Manager (VUM) and it's ability to update the hosts. When attempting to remediate the host I was being given a message stating: The host returns esxupdate error code: 7. Cannot download VIB. Check the Update Manager log files and esxupdate log files for more details.
vCenter Warning

So I do as the error code says, and go check out the logs...

vmware-vum-server.log sample of what I saw:

2011-12-08T10:51:17.916-05:00 [02704 warning 'Libs'] SSLVerifyIsEnabled: failed to read registry value. Falling back to default behavior: verification off. LastError = -2146885628

2011-12-08T10:55:54.054-05:00 [02704 error 'Default'] SSLStreamImpl::BIORead (0c594a48) failed: The specified network name is no longer available.

2011-12-08T10:55:54.054-05:00 [02704 error 'Default'] SSLStreamImpl::DoServerHandshake (0c594a48) SSL_accept failed with BIO Error

2011-12-08T10:55:54.054-05:00 [02704 error 'Ufa.HTTPService'] accept failure class Vmacore::Ssl::SSLException(SSL Exception: BIO Error) on stream (null)

2011-12-08T10:55:54.054-05:00 [02704 error 'Ufa.HTTPService'] stream is NULL - no read scheduled

2011-12-08T10:56:49.625-05:00 [03392 error 'PropertyJournal'] [ValidateChange]INVALID operations on path supportedUpdateProduct["embeddedEsx 4.0.0"]: lastOp=ADD, thisOp=ADD - ADD can only follow REMOVE

2011-12-08T10:56:49.625-05:00 [03392 error 'PropertyJournal'] [ValidateChange]INVALID operations on path supportedUpdateProduct["embeddedEsx 4.1.0"]: lastOp=ADD, thisOp=ADD - ADD can only follow REMOVE

2011-12-08T10:56:49.625-05:00 [03392 error 'PropertyJournal'] [ValidateChange]INVALID operations on path supportedUpdateProduct["esx 4.0.0"]: lastOp=ADD, thisOp=ADD - ADD can only follow REMOVE

2011-12-08T10:56:49.625-05:00 [03392 error 'PropertyJournal'] [ValidateChange]INVALID operations on path supportedUpdateProduct["esx 4.1.0"]: lastOp=ADD, thisOp=ADD - ADD can only follow REMOVE

2011-12-08T10:56:50.347-05:00 [03392 error 'PropertyJournal'] [ValidateChange]INVALID operations on path supportedUpdateProduct["embeddedEsx 4.0.0"]: lastOp=ADD, thisOp=ADD - ADD can only follow REMOVE

2011-12-08T10:56:50.347-05:00 [03392 error 'PropertyJournal'] [ValidateChange]INVALID operations on path supportedUpdateProduct["embeddedEsx 4.1.0"]: lastOp=ADD, thisOp=ADD - ADD can only follow REMOVE

2011-12-08T10:56:50.347-05:00 [03392 error 'PropertyJournal'] [ValidateChange]INVALID operations on path supportedUpdateProduct["esx 4.0.0"]: lastOp=ADD, thisOp=ADD - ADD can only follow REMOVE

2011-12-08T10:56:50.347-05:00 [03392 error 'PropertyJournal'] [ValidateChange]INVALID operations on path supportedUpdateProduct["esx 4.1.0"]: lastOp=ADD, thisOp=ADD - ADD can only follow REMOVE

2011-12-08T10:57:34.344-05:00 [01796 warning 'Libs'] SSLVerifyIsEnabled: failed to read registry value. Falling back to default behavior: verification off. LastError = -2146885628

esxupdate.log sample from the host:

2011-12-08T15:57:29Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/sbin/esxcfg-advcfg', '-q', '-g', '/UserVars/EsximageNetTimeout']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.

2011-12-08T15:57:29Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/sbin/esxcfg-advcfg', '-q', '-g', '/UserVars/EsximageNetRetries']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.

2011-12-08T15:57:29Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/sbin/esxcfg-advcfg', '-q', '-g', '/UserVars/EsximageNetRateLimit']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.

2011-12-08T15:57:29Z esxupdate: esxupdate: INFO: ---
Command: scan
Args: ['scan']
Options: {'nosigcheck': None, 'retry': 5, 'loglevel': None, 'cleancache': None, 'viburls': None, 'meta': ['http://*VIRTUALCENTER*:9084/vum/repository/hostupdate/DELL/metadata_1323354549.zip', 'http://*VIRTUALCENTER*:9084/vum/repository/hostupdate/csco/csco-VEM-5.0.0-metadata.zip', 'http://*VIRTUALCENTER*:9084/vum/repository/hostupdate/vmw/vmw-ESXi-5.0.0-metadata.zip'], 'proxyurl': None, 'timeout': 30.0, 'cachesize': None, 'hamode': True, 'maintenancemode': None}

2011-12-08T15:57:29Z esxupdate: BootBankInstaller.pyc: INFO: Unrecognized value "title=Loading VMware ESXi" in boot.cfg

2011-12-08T15:57:30Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/sbin/bootOption', '-rp']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.

2011-12-08T15:57:30Z esxupdate: downloader: DEBUG: Downloading http://*VIRTUALCENTER*:9084/vum/repository/hostupdate/DELL/metadata_1323354549.zip to /tmp/tmp0HbTco...

2011-12-08T15:57:30Z esxupdate: Metadata.pyc: INFO: Unrecognized file vendor-index.xml in Metadata file

2011-12-08T15:57:30Z esxupdate: downloader: DEBUG: Downloading http://*VIRTUALCENTER*:9084/vum/repository/hostupdate/csco/csco-VEM-5.0.0-metadata.zip to /tmp/tmpBQa1zj...
2011-12-08T15:57:30Z esxupdate: Metadata.pyc: INFO: Unrecognized file vendor-index.xml in Metadata file

2011-12-08T15:57:30Z esxupdate: downloader: DEBUG: Downloading http://*VIRTUALCENTER*:9084/vum/repository/hostupdate/vmw/vmw-ESXi-5.0.0-metadata.zip to /tmp/tmpyQ8Q7O...

2011-12-08T15:57:30Z esxupdate: Metadata.pyc: INFO: Unrecognized file vendor-index.xml in Metadata file

2011-12-08T15:57:30Z esxupdate: BootBankInstaller.pyc: INFO: Unrecognized value "title=Loading VMware ESXi" in boot.cfg

2011-12-08T15:57:30Z esxupdate: HostImage: DEBUG: Live image has been updated but /altbootbank image has not. This means a reboot is not safe.

2011-12-08T15:57:30Z esxupdate: HostImage: DEBUG: Live image has been updated but /altbootbank image has not. This means a reboot is not safe.

2011-12-08T15:57:30Z esxupdate: vmware.runcommand: INFO: runcommand called with: args = '['/usr/sbin/vsish', '-e', '-p', 'cat', '/hardware/bios/dmiInfo']', outfile = 'None', returnoutput = 'True', timeout = '0.0'.

2011-12-08T15:57:30Z esxupdate: esxupdate: INFO: All done!

2011-12-08T15:57:30Z esxupdate: esxupdate: DEBUG: <<<

There wasn't much in there to give me much to go on, however the "Unrecognized file vendor-index.xml in Metadata file" part was a good lead. I was using the default download sources, so that shouldn't be a problem. I turned off the Windows firewall, no luck. I put in the URL to the repository and could get to it just fine.

I don't normally stage the updates, but I went back and clicked on the "Stage" button. That ran just fine, even staged the Dell extension for our EqualLogic MEM. Tried to remediate again, no luck. This time I tried to do just the extension, it worked!

I go back and check out the staged updates, 2 are listed as missing! We've found our problem.
vCenter Warning

I head out to the VMware Download Patches site: http://www.vmware.com/patchmgr/download.portal and download the missing patches and then import them into the VUM Patch Repository and remediate the host again. It worked!

Moral of the story: always check to make sure that the patches are not only listed as available, but that they're able to be staged.

Update...

One thing I may have MAJORLY overlooked... Check the status of your "vmw" and "csco" folders. If they look like "VMW" and "CSCO", they will not work and have to be lower case!

This is not the case with the example I have included above, but I have run into it on another install. Such a simple thing to overlook on accident.

Comments (5) Trackbacks (1)
  1. This was helpfull! Thnx 🙂

  2. Thank you, thank you! CSCO was the root of all my problems!

  3. I had this problem on a newly installed ESX server, the solution was to reboot the server.

    • As a side note to that, and depending on what your situation is, that may not be a viable option. You could probably just restart the management agents and achieve the same results.

  4. It was the reboot that solved our issue.


Leave a Reply