search

vmware / open-vm-tools

Official repository of VMware open-vm-tools project
http://sourceforge.net/projects/open-vm-tools/
2.23k stars 425 forks source link

Customization on Ubuntu Server 20.04: Address already in use #538

Open kam1sh opened 3 years ago

kam1sh commented 3 years ago

Hi! Recently I templated latest Ubuntu in vCloud environment.

When I created first dozen VMs, it worked fine. I even wrote a blogpost about my success somwhere.

But now, when I created another dozen VMs, from the same template, with almost same settings and same customization script, something went wrong and script doesn't executed. This is what I got in logs:

# cat /var/log/vmware-imc/toolsDeployPkg.log 
[2021-08-29T22:19:50.901Z] [   debug] ## Starting deploy pkg operation
[2021-08-29T22:19:50.901Z] [   debug] Deploying /var/run/2e3a09f4/cust1879487095701364799.cab
[2021-08-29T22:19:50.901Z] [    info] Initializing deployment module.
[2021-08-29T22:19:50.901Z] [    info] Cleaning old state files.
[2021-08-29T22:19:50.901Z] [    info] EXIT STATE 'INPROGRESS'.
[2021-08-29T22:19:50.901Z] [    info] EXIT STATE 'Done'.
[2021-08-29T22:19:50.901Z] [   debug] Setting deploy error: 'Error removing lock '/var/log/.vmware-deploy.Done'.(No such file or directory)'.
[2021-08-29T22:19:50.901Z] [    info] EXIT STATE 'ERRORED'.
[2021-08-29T22:19:50.901Z] [   debug] Setting deploy error: 'Error removing lock '/var/log/.vmware-deploy.ERRORED'.(No such file or directory)'.
[2021-08-29T22:19:50.901Z] [   debug] Setting deploy error: 'Success.'.
[2021-08-29T22:19:50.901Z] [    info] Deploying cabinet file '/var/run/2e3a09f4/cust1879487095701364799.cab'.
[2021-08-29T22:19:50.901Z] [    info] Transitioning from state '(null)' to state 'INPROGRESS'.
[2021-08-29T22:19:50.901Z] [    info] ENTER STATE 'INPROGRESS'.
[2021-08-29T22:19:50.902Z] [    info] Reading cabinet file '/var/run/2e3a09f4/cust1879487095701364799.cab' and will extract it to '/var/run/.vmware-imgcust-dQ8gdsJ'.
[2021-08-29T22:19:50.902Z] [   debug] Setting deploy error: 'Error reading header. (Address already in use)'.
[2021-08-29T22:19:50.902Z] [   debug] Setting deploy error: 'Error extracting package header information. (Error reading header. (Address already in use))'.
[2021-08-29T22:19:50.902Z] [    info] Launching cleanup.
[2021-08-29T22:19:50.902Z] [   debug] Command to exec : '/bin/rm'.
[2021-08-29T22:19:50.902Z] [    info] sizeof ProcessInternal is 56
[2021-08-29T22:19:50.902Z] [    info] Returning, pending output from stdout
[2021-08-29T22:19:50.902Z] [    info] Returning, pending output from stderr
[2021-08-29T22:19:50.903Z] [    info] Process exited normally after 0 seconds, returned 0
[2021-08-29T22:19:50.903Z] [    info] No more output from stdout
[2021-08-29T22:19:50.903Z] [    info] No more output from stderr
[2021-08-29T22:19:50.903Z] [    info] Customization command output:
''.
[2021-08-29T22:19:50.903Z] [   error] Deploy error: 'Error extracting package header information. (Error reading header. (Address already in use))'.
[2021-08-29T22:19:50.903Z] [   error] Package deploy failed in DeployPkg_DeployPackageFromFile
[2021-08-29T22:19:50.903Z] [   debug] ## Closing log

# cat /var/log/vmware-vmsvc-root.log 
[2021-08-29T22:19:50.059Z] [ message] [vmsvc] Log caching is enabled with maxCacheEntries=4096.
[2021-08-29T22:19:50.059Z] [ message] [vmsvc] Core dump limit set to -1
[2021-08-29T22:19:50.059Z] [ message] [vmtoolsd] Tools Version: 11.2.5.26209 (build-17337674)
[2021-08-29T22:19:50.807Z] [ message] [vmtoolsd] Plugin 'hgfsServer' initialized.
[2021-08-29T22:19:50.807Z] [ message] [vix] QueryVGAuthConfig: vgauth usage is: 1
[2021-08-29T22:19:50.807Z] [ message] [vmtoolsd] Plugin 'vix' initialized.
[2021-08-29T22:19:50.807Z] [ message] [vmtoolsd] Plugin 'appInfo' initialized.
[2021-08-29T22:19:50.807Z] [ message] [vmtoolsd] Plugin 'deployPkg' initialized.
[2021-08-29T22:19:50.807Z] [ message] [vmtoolsd] Plugin 'guestInfo' initialized.
[2021-08-29T22:19:50.807Z] [ message] [vmtoolsd] Plugin 'powerops' initialized.
[2021-08-29T22:19:50.807Z] [ message] [vmtoolsd] Plugin 'timeSync' initialized.
[2021-08-29T22:19:50.807Z] [ message] [vmtoolsd] Plugin 'vmbackup' initialized.
[2021-08-29T22:19:50.812Z] [ message] [vix] VixTools_ProcessVixCommand: command 62
[2021-08-29T22:19:50.892Z] [ message] [vix] ToolsDaemonTcloReceiveVixCommand: command 62, additionalError = 17
[2021-08-29T22:19:50.893Z] [ message] [powerops] Executing script: '/etc/vmware-tools/poweron-vm-default'
[2021-08-29T22:19:50.903Z] [ warning] [deployPkg] DeployPkgInGuest failed, error = 5
[2021-08-29T22:19:51.069Z] [ message] [powerops] Script exit code: 0, success = 1

And also ovfEnv:

# vmware-rpctool 'info-get guestinfo.ovfEnv'
<?xml version="1.0" encoding="UTF-8"?>
<Environment
     xmlns="http://schemas.dmtf.org/ovf/environment/1"
     xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
     xmlns:oe="http://schemas.dmtf.org/ovf/environment/1"
     xmlns:ve="http://www.vmware.com/schema/ovfenv"
     oe:id=""
     ve:vCenterId="vm-697149">
   <PlatformSection>
      <Kind>VMware ESXi</Kind>
      <Version>6.7.0</Version>
      <Vendor>VMware, Inc.</Vendor>
      <Locale>en</Locale>
   </PlatformSection>
   <PropertySection>
         <Property oe:key="local-hostname" oe:value="els1"/>
         <Property oe:key="user-data" oe:value="..."/>
   </PropertySection>
   <ve:EthernetAdapterSection>
      <ve:Adapter ve:mac="00:50:56:0f:29:d7" ve:network="vxw-dvs-166-virtualwire-1867-sid-40144-dvs.VCDVSfed-73-int-2f89fbe1-c91a-49a5-99" ve:unitNumber="7"/>
   </ve:EthernetAdapterSection>
</Environment>

I did everything that I know from common workaronds - tmpfiles, disable_vmware_customization: false in cloud-init, dbus... nothing helped.

I'll recreate whole network later, but anyway... Maybe I'm not the only one or someone may know the cause?

versions

# vmtoolsd --version
VMware Tools daemon, version 11.2.5.26209 (build-17337674)

# lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 20.04.3 LTS
Release:        20.04
Codename:       focal

vCloud Director version: 10.0.0.16869149 Wed Sep 09 06:53:44 UTC 2020
rongz609 commented 3 years ago

Hi kam1sh,

Thanks for raising this error. I think there is something wrong with the .cab package. But unfortunately it will be removed in the clean up stage at the end of customization. So to debug this error, my idea is to write a script which runs as a demon in the OS booting process and capture the cab file /var/run/ /cust*.cab, back the cab file in another directory. I can try to write this script, but you need to upload this script into your test VM and regenerate another VM template. And my question is can you always reproduce this error in your place? Especially when you regenerated your VM template.

rongz609 commented 3 years ago

And can you share your VM template with me? I can try to reproduce it in my place.

Thanks.

kam1sh commented 3 years ago

Hello, rongz609!

I can attach any script to a vm, of course.

can you always reproduce this error in your place? Especially when you regenerated your VM template

Yes, I recreated template from the ISO installer, and error still persists.

And can you share your VM template with me?

Right now I have unstable connection, so I couldn't download image on my device and then upload on file share.

But the image set up is trivial:

apt update && apt upgrade -y && reboot
rm /etc/netplan/00-installer-config.yaml
echo 'disable_vmware_customization: false' > /etc/cloud/cloud.cfg.d/91_vmware_cust.cfg
dpkg-reconfigure cloud-init # leave only OVF
cloud-init clean --logs
rm -r /var/log/vmware*
poweroff

Also, I sent a ticket to datacenter support, but they responded to me that user-created images is not their responsibility :(

rongz609 commented 3 years ago

Hi Kam1sh,

Sorry for the late update. I found it's difficult to capture the customization cab package during guest OS booting. Because the cab package exists a very shot time, it's hard to capture it.

And one more question, have you tried other VM templates excepting the not working one? If other VM templates can work well, then we can know the problem is in your VM template. And if not, the problem is in vCD product.

Could you fill a support request on vcloud director product about this issue? Then GSS can help you to upload your VM template.

Thanks. Regards.