Customization on Ubuntu 20.04 not working (vCenter Server Appliance version 6.7u3j)

jblaine commented 3 years ago

OS: Ubuntu 20.04 vCenter Server: 6.7u3j open-vm-tools: 11.1.0-2~ubuntu20.04.1

We are unable to customize Ubuntu 20.04 VMs when using a version of vCenter that should cover Ubuntu 20.04.

As a start to fixing this, I've already had to rebuild our template to have the ifconfig command found in the net-utils package. I also had to make a symlink named /etc/dhcp3 pointing to /etc/dhcp. Both of those fixes were based off of what I was seeing in the log.

But now, after that, it is not clear to me what is causing the next failure in customization or why we're hitting this if it is theoretically supported by our vCenter version.

The log below shows "Deployment succeeded" but the IP address of the host is not correct/customized, etc.

[2020-10-07T14:26:39.938Z] [   debug] ## Starting deploy pkg operation
[2020-10-07T14:26:39.938Z] [   debug] Deploying /var/run/3807d697/cust2223304382727761285.cab
[2020-10-07T14:26:39.938Z] [    info] Initializing deployment module.

[2020-10-07T14:26:39.938Z] [    info] Cleaning old state files.

[2020-10-07T14:26:39.938Z] [    info] EXIT STATE 'INPROGRESS'.

[2020-10-07T14:26:39.938Z] [   debug] Setting deploy error: 'Error removing lock '/var/log/.vmware-deploy.INPROGRESS'.(No such file or directory)'.

[2020-10-07T14:26:39.938Z] [    info] EXIT STATE 'Done'.

[2020-10-07T14:26:39.939Z] [    info] EXIT STATE 'ERRORED'.

[2020-10-07T14:26:39.939Z] [   debug] Setting deploy error: 'Error removing lock '/var/log/.vmware-deploy.ERRORED'.(No such file or directory)'.

[2020-10-07T14:26:39.939Z] [   debug] Setting deploy error: 'Success.'.

[2020-10-07T14:26:39.939Z] [    info] Deploying cabinet file '/var/run/3807d697/cust2223304382727761285.cab'.

[2020-10-07T14:26:39.939Z] [    info] Transitioning from state '(null)' to state 'INPROGRESS'.

[2020-10-07T14:26:39.939Z] [    info] ENTER STATE 'INPROGRESS'.

[2020-10-07T14:26:39.941Z] [    info] Reading cabinet file '/var/run/3807d697/cust2223304382727761285.cab' and will extract it to '/var/run/.vmware-imgcust-d445o1S'.

[2020-10-07T14:26:39.941Z] [    info] Flags in the header: 0.

[2020-10-07T14:26:39.941Z] [    info] Original deployment command: '/usr/bin/perl -I/tmp/.vmware/linux/deploy/scripts /tmp/.vmware/linux/deploy/scripts/Customize.pl /tmp/.vmware/linux/deploy/cust.cfg'.

[2020-10-07T14:26:39.941Z] [    info] Actual deployment command: '/usr/bin/perl -I/var/run/.vmware-imgcust-d445o1S/scripts /var/run/.vmware-imgcust-d445o1S/scripts/Customize.pl /var/run/.vmware-imgcust-d445o1S/cust.cfg'.

[2020-10-07T14:26:39.941Z] [    info] Extracting package files.

[2020-10-07T14:26:40.038Z] [   debug] Check if cust.cfg exists.

[2020-10-07T14:26:40.038Z] [    info] cust.cfg is found in '/var/run/.vmware-imgcust-d445o1S' directory.

[2020-10-07T14:26:40.038Z] [   debug] Command to exec : '/usr/bin/cloud-init'.

[2020-10-07T14:26:40.038Z] [    info] sizeof ProcessInternal is 56

[2020-10-07T14:26:40.045Z] [    info] Returning, pending output from stdout
[2020-10-07T14:26:40.052Z] [    info] Returning, pending output from stderr
[2020-10-07T14:26:40.061Z] [    info] Process exited normally after 0 seconds, returned 127
[2020-10-07T14:26:40.061Z] [    info] No more output from stdout
[2020-10-07T14:26:40.061Z] [    info] No more output from stderr
[2020-10-07T14:26:40.061Z] [    info] Customization command output: ''.

[2020-10-07T14:26:40.061Z] [   error] Customization command failed with exitcode: 127, stderr: ''.

[2020-10-07T14:26:40.061Z] [    info] cloud-init is not installed.

[2020-10-07T14:26:40.061Z] [    info] Executing traditional GOSC workflow.

[2020-10-07T14:26:40.061Z] [   debug] Command to exec : '/usr/bin/perl'.

[2020-10-07T14:26:40.061Z] [    info] sizeof ProcessInternal is 56

[2020-10-07T14:26:40.062Z] [    info] Returning, pending output from stdout
[2020-10-07T14:26:40.062Z] [    info] Returning, pending output from stderr
[2020-10-07T14:26:41.600Z] [    info] Saving output from stdout
[2020-10-07T14:26:41.600Z] [    info] Saving output from stdout
[2020-10-07T14:26:41.600Z] [    info] Saving output from stdout
[2020-10-07T14:26:41.600Z] [    info] Saving output from stdout
[2020-10-07T14:26:41.700Z] [    info] Saving output from stdout
[2020-10-07T14:26:41.803Z] [    info] Saving output from stdout
[2020-10-07T14:26:41.904Z] [    info] Saving output from stdout
[2020-10-07T14:26:42.016Z] [    info] Saving output from stdout
[2020-10-07T14:26:42.116Z] [    info] Saving output from stdout
[2020-10-07T14:26:42.416Z] [    info] Saving output from stdout
[2020-10-07T14:26:42.416Z] [    info] Saving output from stdout
[2020-10-07T14:26:42.416Z] [    info] Saving output from stdout
[2020-10-07T14:26:42.416Z] [    info] Saving output from stdout
[2020-10-07T14:26:42.516Z] [    info] Saving output from stdout
[2020-10-07T14:26:42.517Z] [    info] Saving output from stdout
[2020-10-07T14:26:42.617Z] [    info] Process exited normally after 2 seconds, returned 0
[2020-10-07T14:26:42.617Z] [    info] Saving output from stdout
[2020-10-07T14:26:42.617Z] [    info] No more output from stdout
[2020-10-07T14:26:42.617Z] [    info] No more output from stderr
[2020-10-07T14:26:42.617Z] [    info] Customization command output: 'INFO: Opening file name /var/run/.vmware-imgcust-d445o1S/cust.cfg. 
DEBUG: Processing line: '[NETWORK]' 
DEBUG: FOUND CATEGORY = NETWORK 
DEBUG: Processing line: 'NETWORKING = yes' 
DEBUG: ADDED KEY-VAL :: 'NETWORK|NETWORKING' = 'yes' 
DEBUG: Processing line: 'BOOTPROTO = dhcp' 
DEBUG: ADDED KEY-VAL :: 'NETWORK|BOOTPROTO' = 'dhcp' 
DEBUG: Processing line: 'HOSTNAME = ub20test2' 
DEBUG: ADDED KEY-VAL :: 'NETWORK|HOSTNAME' = 'ub20test2' 
DEBUG: Processing line: 'DOMAINNAME = our.org' 
DEBUG: ADDED KEY-VAL :: 'NETWORK|DOMAINNAME' = 'our.org' 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '[NIC-CONFIG]' 
DEBUG: FOUND CATEGORY = NIC-CONFIG 
DEBUG: Processing line: 'NICS = NIC1' 
DEBUG: ADDED KEY-VAL :: 'NIC-CONFIG|NICS' = 'NIC1' 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '[NIC1]' 
DEBUG: FOUND CATEGORY = NIC1 
DEBUG: Processing line: 'MACADDR = 00:50:56:01:0f:36' 
DEBUG: ADDED KEY-VAL :: 'NIC1|MACADDR' = '00:50:56:01:0f:36' 
DEBUG: Processing line: 'PRIMARY = yes' 
DEBUG: ADDED KEY-VAL :: 'NIC1|PRIMARY' = 'yes' 
DEBUG: Processing line: 'ONBOOT = yes' 
DEBUG: ADDED KEY-VAL :: 'NIC1|ONBOOT' = 'yes' 
DEBUG: Processing line: 'IPv4_MODE = BACKWARDS_COMPATIBLE' 
DEBUG: ADDED KEY-VAL :: 'NIC1|IPv4_MODE' = 'BACKWARDS_COMPATIBLE' 
DEBUG: Processing line: 'BOOTPROTO = static' 
DEBUG: ADDED KEY-VAL :: 'NIC1|BOOTPROTO' = 'static' 
DEBUG: Processing line: 'IPADDR = 10.8.34.116' 
DEBUG: ADDED KEY-VAL :: 'NIC1|IPADDR' = '10.8.34.116' 
DEBUG: Processing line: 'NETMASK = 255.255.240.0' 
DEBUG: ADDED KEY-VAL :: 'NIC1|NETMASK' = '255.255.240.0' 
DEBUG: Processing line: 'GATEWAY = 10.8.32.1' 
DEBUG: ADDED KEY-VAL :: 'NIC1|GATEWAY' = '10.8.32.1' 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '[DNS]' 
DEBUG: FOUND CATEGORY = DNS 
DEBUG: Processing line: 'DNSFROMDHCP=no' 
DEBUG: ADDED KEY-VAL :: 'DNS|DNSFROMDHCP' = 'no' 
DEBUG: Processing line: 'SUFFIX|1 = our.org' 
DEBUG: ADDED KEY-VAL :: 'DNS|SUFFIX|1' = 'our.org' 
DEBUG: Processing line: 'NAMESERVER|1 = 10.20.100.53' 
DEBUG: ADDED KEY-VAL :: 'DNS|NAMESERVER|1' = '10.20.100.53' 
DEBUG: Processing line: 'NAMESERVER|2 = 10.20.200.53' 
DEBUG: ADDED KEY-VAL :: 'DNS|NAMESERVER|2' = '10.20.200.53' 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '[MISC]' 
DEBUG: FOUND CATEGORY = MISC 
DEBUG: Processing line: 'MARKER-ID=54f16355-37fe-40c7-88dc-f1cecc136fc5' 
DEBUG: ADDED KEY-VAL :: 'MISC|MARKER-ID' = '54f16355-37fe-40c7-88dc-f1cecc136fc5' 
DEBUG: Processing line: 'POST-GC-STATUS=yes' 
DEBUG: ADDED KEY-VAL :: 'MISC|POST-GC-STATUS' = 'yes' 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '[PASSWORD]' 
DEBUG: FOUND CATEGORY = PASSWORD 
DEBUG: Processing line: 'RESET=no' 
DEBUG: ADDED KEY-VAL :: 'PASSWORD|RESET' = 'no' 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

DEBUG: Reading /etc/os-release file ...  
DEBUG: opening file /etc/os-release. 
DEBUG: Match found   : Line = PRETTY_NAME="Ubuntu 20.04.1 LTS"

DEBUG: Actual String : "Ubuntu 20.04.1 LTS" 
DEBUG: "Ubuntu 20.04.1 LTS" 
WARNING: Amazon Linux flavor not detected 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

WARNING: RedHat release file not available. Ignoring it. 
WARNING: Redhat flavor not detected 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

WARNING: RedHat release file not available. Ignoring it. 
WARNING: Redhat flavor not detected 
DEBUG: Command: 'cat /etc/lsb-release' 
DEBUG: Result: DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=20.04
DISTRIB_CODENAME=focal
DISTRIB_DESCRIPTION="Ubuntu 20.04.1 LTS"

DEBUG: Exit Code: 0 
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

DEBUG: Command: 'cat /etc/lsb-release' 
DEBUG: Result: DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=20.04
DISTRIB_CODENAME=focal
DISTRIB_DESCRIPTION="Ubuntu 20.04.1 LTS"

DEBUG: Exit Code: 0 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

DEBUG: Command: 'cat /etc/lsb-release' 
DEBUG: Result: DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=20.04
DISTRIB_CODENAME=focal
DISTRIB_DESCRIPTION="Ubuntu 20.04.1 LTS"

DEBUG: Exit Code: 0 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

DEBUG: Command: 'cat /etc/lsb-release' 
DEBUG: Result: DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=20.04
DISTRIB_CODENAME=focal
DISTRIB_DESCRIPTION="Ubuntu 20.04.1 LTS"

DEBUG: Exit Code: 0 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

DEBUG: Command: 'cat /etc/lsb-release' 
DEBUG: Result: DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=20.04
DISTRIB_CODENAME=focal
DISTRIB_DESCRIPTION="Ubuntu 20.04.1 LTS"

DEBUG: Exit Code: 0 
INFO: Detected distribution: Ubuntu Linux Distribution 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

INFO: Detected distribution flavour: Ubuntu 
INFO: Get Tools Daemon Command Line 
DEBUG: Command: 'ps -C vmtoolsd -o cmd=' 
DEBUG: Result: /usr/bin/vmtoolsd

DEBUG: Exit Code: 0 
DEBUG: Command: '/usr/bin/vmtoolsd --cmd "info-set guestinfo.gc.status Started"' 
DEBUG: Result: 

DEBUG: Exit Code: 0 
INFO: Checking if can run 'Customize' workflow 
INFO: Calling 'Customize' method 
DEBUG: Command: 'hostname 2>/dev/null' 
DEBUG: Result: ub20test

DEBUG: Exit Code: 0 
DEBUG: TimedCommand: 'hostname -f 2>/dev/null' with timeout of 5 sec 
DEBUG: Fetching result from /tmp/timed_out_tmp_file_598 
DEBUG: TimedResult: ub20test.our.org

DEBUG: opening file /etc/hostname. 
DEBUG: Match found   : Line = ub20test 
DEBUG: Actual String : ub20test 
INFO: OLD HOST NAME = ub20test 
INFO: Handling pre-customization ...  
INFO: RunCustomScript invoked in '/var/run/.vmware-imgcust-d445o1S/' for 'precustomization' 
INFO: No customization script to run 
INFO: RunCustomScript has completed 
INFO: Customizing Network settings ...  
INFO: Erasing DHCP leases 
DEBUG: Command: 'pkill dhclient' 
DEBUG: Result:  
DEBUG: Exit Code: 256 
DEBUG: Command: 'rm -f /var/lib/dhcp/*' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
DEBUG: Host name is ub20test2 
DEBUG: opening file for writing (/etc/hostname). 
DEBUG: Command: 'chmod 644 /etc/hostname' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Customizing NICS ...  
DEBUG: Command: 'modprobe pcnet32 2> /dev/null' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
DEBUG: Command: '/sbin/ifconfig eth0 2> /dev/null' 
DEBUG: Result:  
DEBUG: Exit Code: 256 
INFO: Customizing NICS. { NIC1 } 
INFO: Customizing NIC NIC1 
DEBUG: Command: '/sbin/ifconfig -a' 
DEBUG: Result: ens160: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 10.8.35.56  netmask 255.255.240.0  broadcast 10.8.47.255
        ether 00:50:56:01:0f:36  txqueuelen 1000  (Ethernet)
        RX packets 4  bytes 454 (454.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 10  bytes 773 (773.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet 127.0.0.1  netmask 255.0.0.0
        inet6 ::1  prefixlen 128  scopeid 0x10<host>
        loop  txqueuelen 1000  (Local Loopback)
        RX packets 95  bytes 7469 (7.4 KB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 95  bytes 7469 (7.4 KB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

DEBUG: Exit Code: 0 
INFO: NIC suffix = ether 
INFO: Configuring gateway from the primary NIC 'NIC1' 
INFO: Query config for ^(NIC1\|IPv6ADDR\|) 
INFO: Query config for ^(NIC1\|IPv6NETMASK\|) 
INFO: Query config for ^NIC1(\|IPv6GATEWAY\|) 
DEBUG: Command: 'mv /etc/network/interfaces /etc/network/interfaces.BeforeVMwareCustomization' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
DEBUG: opening file for writing (/etc/network/interfaces). 
INFO: Customizing Hosts file ...  
DEBUG: Old hostname=[ub20test] 
DEBUG: Old FQDN=[ub20test.our.org] 
DEBUG: New hostname=[ub20test2] 
DEBUG: Building FQDN. HostnameFQDN: ub20test2, Domainname: our.org 
DEBUG: New FQDN=[ub20test2.our.org] 
DEBUG: opening file /etc/hosts. 
DEBUG: Line (inp): 127.0.0.1    localhost

DEBUG: Line (inp): 127.0.1.1    ub20-desk-tplt

DEBUG: Line (inp): 

DEBUG: Line (inp): # The following lines are desirable for IPv6 capable hosts

DEBUG: Line (inp): ::1     ip6-localhost ip6-loopback

DEBUG: Line (inp): fe00::0 ip6-localnet

DEBUG: Line (inp): ff00::0 ip6-mcastprefix

DEBUG: Line (inp): ff02::1 ip6-allnodes

DEBUG: Line (inp): ff02::2 ip6-allrouters

DEBUG: Line (inp): 

DEBUG: Line (inp): 

DEBUG: Line (inp): 10.8.35.56   ub20test.our.org ub20test

DEBUG: Static ip entry added 
DEBUG: Line (out): 127.0.0.1    localhost

DEBUG: Line (out): 127.0.1.1    ub20-desk-tplt

DEBUG: Line (out): 

DEBUG: Line (out): # The following lines are desirable for IPv6 capable hosts

DEBUG: Line (out): ::1     ip6-localhost ip6-loopback

DEBUG: Line (out): fe00::0 ip6-localnet

DEBUG: Line (out): ff00::0 ip6-mcastprefix

DEBUG: Line (out): ff02::1 ip6-allnodes

DEBUG: Line (out): ff02::2 ip6-allrouters

DEBUG: Line (out): 

DEBUG: Line (out): 

DEBUG: Line (out): 
10.8.34.116 ub20test2.our.org ub20test2

DEBUG: opening file for writing (/etc/hosts). 
DEBUG: Command: 'chmod 644 /etc/hosts' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Customizing DNS ...  
DEBUG: opening file /etc/nsswitch.conf. 
DEBUG: opening file for writing (/etc/nsswitch.conf). 
DEBUG: Command: 'chmod 644 /etc/nsswitch.conf' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Query config for ^(DNS\|SUFFIX\|) 
DEBUG: Match Found : DNS|SUFFIX|1 
DEBUG: 0 
INFO: Query config for ^(DNS\|NAMESERVER\|) 
DEBUG: Match Found : DNS|NAMESERVER|2 
DEBUG: 0 
DEBUG: Match Found : DNS|NAMESERVER|1 
DEBUG: 1 
DEBUG: opening file for writing (/etc/resolv.conf). 
DEBUG: Command: 'chmod 644 /etc/resolv.conf' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Query config for ^(DNS\|SUFFIX\|) 
DEBUG: Match Found : DNS|SUFFIX|1 
DEBUG: 0 
DEBUG: opening file for writing (/etc/dhcp3/dhclient.conf). 
DEBUG: Command: 'chmod 644 /etc/dhcp3/dhclient.conf' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Query config for ^(DNS\|NAMESERVER\|) 
DEBUG: Match Found : DNS|NAMESERVER|2 
DEBUG: 0 
DEBUG: Match Found : DNS|NAMESERVER|1 
DEBUG: 1 
DEBUG: opening file for writing (/etc/dhcp3/dhclient.conf). 
DEBUG: Command: 'chmod 644 /etc/dhcp3/dhclient.conf' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Customizing Date&Time ...  
INFO: Handling password settings ...  
INFO: Changing password is not needed 
INFO: Handling post-customization ...  
INFO: RunCustomScript invoked in '/var/run/.vmware-imgcust-d445o1S/' for 'postcustomization' 
INFO: No customization script to run 
INFO: RunCustomScript has completed 
INFO: Handling marker creation ...  
DEBUG: Command: '/bin/rm -f /.markerfile-*.txt' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
DEBUG: Command: '/bin/touch /.markerfile-54f16355-37fe-40c7-88dc-f1cecc136fc5.txt' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Get Tools Daemon Command Line 
DEBUG: Command: 'ps -C vmtoolsd -o cmd=' 
DEBUG: Result: /usr/bin/vmtoolsd

DEBUG: Exit Code: 0 
DEBUG: Command: '/usr/bin/vmtoolsd --cmd "info-set guestinfo.gc.status Successful"' 
DEBUG: Result: 

DEBUG: Exit Code: 0 
INFO: Customization completed. 
'.

[2020-10-07T14:26:42.617Z] [    info] No nics to enable.

[2020-10-07T14:26:42.621Z] [    info] Transitioning from state 'INPROGRESS' to state 'Done'.

[2020-10-07T14:26:42.621Z] [    info] ENTER STATE 'Done'.

[2020-10-07T14:26:42.621Z] [    info] EXIT STATE 'INPROGRESS'.

[2020-10-07T14:26:42.621Z] [    info] Deployment succeeded.

[2020-10-07T14:26:42.621Z] [    info] Launching cleanup.

[2020-10-07T14:26:42.621Z] [   debug] Command to exec : '/bin/rm'.

[2020-10-07T14:26:42.621Z] [    info] sizeof ProcessInternal is 56

[2020-10-07T14:26:42.622Z] [    info] Returning, pending output from stdout
[2020-10-07T14:26:42.622Z] [    info] Returning, pending output from stderr
[2020-10-07T14:26:42.722Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-07T14:26:42.722Z] [    info] No more output from stdout
[2020-10-07T14:26:42.722Z] [    info] No more output from stderr
[2020-10-07T14:26:42.722Z] [    info] Customization command output: ''.

[2020-10-07T14:26:42.722Z] [    info] sSkipReboot: 'false', forceSkipReboot 'false'.

[2020-10-07T14:26:42.722Z] [   debug] Ran DeployPkg_DeployPackageFromFile successfully
[2020-10-07T14:26:42.722Z] [   debug] ## Closing log
[2020-10-07T14:26:42.723Z] [    info] Trigger reboot.

[2020-10-07T14:26:42.723Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-07T14:26:42.723Z] [    info] sizeof ProcessInternal is 56

[2020-10-07T14:26:42.724Z] [    info] Returning, pending output from stdout
[2020-10-07T14:26:42.724Z] [    info] Returning, pending output from stderr
[2020-10-07T14:26:43.424Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-07T14:26:43.424Z] [    info] No more output from stdout
[2020-10-07T14:26:43.424Z] [    info] No more output from stderr
[2020-10-07T14:26:43.424Z] [    info] Customization command output: ''.

[2020-10-07T14:26:44.425Z] [    info] Rebooting.

[2020-10-07T14:26:44.425Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-07T14:26:44.425Z] [    info] sizeof ProcessInternal is 56

[2020-10-07T14:26:44.425Z] [    info] Returning, pending output from stdout
[2020-10-07T14:26:44.425Z] [    info] Returning, pending output from stderr
[2020-10-07T14:26:44.525Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-07T14:26:44.525Z] [    info] No more output from stdout
[2020-10-07T14:26:44.525Z] [    info] No more output from stderr
[2020-10-07T14:26:44.525Z] [    info] Customization command output: ''.

[2020-10-07T14:26:45.525Z] [    info] Rebooting.

[2020-10-07T14:26:45.525Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-07T14:26:45.525Z] [    info] sizeof ProcessInternal is 56

[2020-10-07T14:26:45.526Z] [    info] Returning, pending output from stdout
[2020-10-07T14:26:45.526Z] [    info] Returning, pending output from stderr
[2020-10-07T14:26:46.427Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-07T14:26:46.427Z] [    info] No more output from stdout
[2020-10-07T14:26:46.427Z] [    info] No more output from stderr
[2020-10-07T14:26:46.427Z] [    info] Customization command output: ''.

[2020-10-07T14:26:47.428Z] [    info] Rebooting.

[2020-10-07T14:26:47.428Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-07T14:26:47.428Z] [    info] sizeof ProcessInternal is 56

[2020-10-07T14:26:47.428Z] [    info] Returning, pending output from stdout
[2020-10-07T14:26:47.428Z] [    info] Returning, pending output from stderr
[2020-10-07T14:26:47.628Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-07T14:26:47.628Z] [    info] No more output from stdout
[2020-10-07T14:26:47.628Z] [    info] No more output from stderr
[2020-10-07T14:26:47.628Z] [    info] Customization command output: ''.

[2020-10-07T14:26:48.447Z] [    info] Rebooting.

[2020-10-07T14:26:48.447Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-07T14:26:48.447Z] [    info] sizeof ProcessInternal is 56

[2020-10-07T14:26:48.447Z] [    info] Returning, pending output from stdout
[2020-10-07T14:26:48.447Z] [    info] Returning, pending output from stderr
[2020-10-07T14:26:48.548Z] [    info] Process exited normally after 0 seconds, returned 1
[2020-10-07T14:26:48.548Z] [    info] No more output from stdout
[2020-10-07T14:26:48.548Z] [    info] Saving output from stderr
[2020-10-07T14:26:48.548Z] [    info] No more output from stderr
[2020-10-07T14:26:48.548Z] [    info] Customization command output: ''.

[2020-10-07T14:26:48.548Z] [   error] Customization command failed with exitcode: 1, stderr: 'Failed to connect to bus: Connection refused
Failed to open initctl fifo: No such device or address
Failed to talk to init daemon.
'.

[2020-10-07T14:26:49.548Z] [    info] Reboot has been triggered.

[2020-10-07T14:26:49.548Z] [   debug] Ran DeployPkg_DeployPackageFromFile successfully
[2020-10-07T14:26:49.548Z] [   debug] ## Closing log

PengpengSun commented 3 years ago

INFO: Detected distribution: Ubuntu Linux Distribution

This line in the toolsDeployPkg.log shows customization scripts did NOT detect the correct Ubuntu version.

From the log, I think you are using vCD, could you please share the vCD build info?

PengpengSun commented 3 years ago

And please check this issue: https://github.com/vmware/open-vm-tools/issues/453

jblaine commented 3 years ago

@PengpengSun Thanks for the replies. We're going to upgrade vCD from 10.1.0 to 10.1.2 later in the week and see if there's any improvement. I will report back with my findings.

PS: What's strange to me is that I can't find the string "Detected distribution" anywhere in this repo's code. I was going to browse around in the code related to this issue...

PengpengSun commented 3 years ago

Yes, please upgrade to 10.1.2 and have a retry, let me know if you still hit this issue after that.

And No, it's not open-vm-tools code, it's a customization code output log.

jblaine commented 3 years ago

We've gotten further now with VCD 10.1.2, but the hostname is not being properly set. It's staying "ub20test" (our template's VM name). Also, there appears to be some crazy loop going on in the last ~100+ lines shown below.

[2020-10-30T20:11:18.393Z] [   debug] ## Starting deploy pkg operation
[2020-10-30T20:11:18.394Z] [   debug] Deploying /var/run/32e144e9/cust3779629064576285615.cab
[2020-10-30T20:11:18.394Z] [    info] Initializing deployment module.

[2020-10-30T20:11:18.394Z] [    info] Cleaning old state files.

[2020-10-30T20:11:18.394Z] [    info] EXIT STATE 'INPROGRESS'.

[2020-10-30T20:11:18.394Z] [   debug] Setting deploy error: 'Error removing lock '/var/log/.vmware-deploy.INPROGRESS'.(No such file or directory)'.

[2020-10-30T20:11:18.394Z] [    info] EXIT STATE 'Done'.

[2020-10-30T20:11:18.394Z] [    info] EXIT STATE 'ERRORED'.

[2020-10-30T20:11:18.394Z] [   debug] Setting deploy error: 'Error removing lock '/var/log/.vmware-deploy.ERRORED'.(No such file or directory)'.

[2020-10-30T20:11:18.394Z] [   debug] Setting deploy error: 'Success.'.

[2020-10-30T20:11:18.394Z] [    info] Deploying cabinet file '/var/run/32e144e9/cust3779629064576285615.cab'.

[2020-10-30T20:11:18.394Z] [    info] Transitioning from state '(null)' to state 'INPROGRESS'.

[2020-10-30T20:11:18.394Z] [    info] ENTER STATE 'INPROGRESS'.

[2020-10-30T20:11:18.396Z] [    info] Reading cabinet file '/var/run/32e144e9/cust3779629064576285615.cab' and will extract it to '/var/run/.vmware-imgcust-d8hX0vf'.

[2020-10-30T20:11:18.396Z] [    info] Flags in the header: 0.

[2020-10-30T20:11:18.396Z] [    info] Original deployment command: '/usr/bin/perl -I/tmp/.vmware/linux/deploy/scripts /tmp/.vmware/linux/deploy/scripts/Customize.pl /tmp/.vmware/linux/deploy/cust.cfg'.

[2020-10-30T20:11:18.396Z] [    info] Actual deployment command: '/usr/bin/perl -I/var/run/.vmware-imgcust-d8hX0vf/scripts /var/run/.vmware-imgcust-d8hX0vf/scripts/Customize.pl /var/run/.vmware-imgcust-d8hX0vf/cust.cfg'.

[2020-10-30T20:11:18.396Z] [    info] Extracting package files.

[2020-10-30T20:11:18.527Z] [   debug] Check if cust.cfg exists.

[2020-10-30T20:11:18.527Z] [    info] cust.cfg is found in '/var/run/.vmware-imgcust-d8hX0vf' directory.

[2020-10-30T20:11:18.527Z] [   debug] Command to exec : '/usr/bin/cloud-init'.

[2020-10-30T20:11:18.528Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:18.528Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:18.529Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:18.544Z] [    info] Process exited normally after 0 seconds, returned 127
[2020-10-30T20:11:18.544Z] [    info] No more output from stdout
[2020-10-30T20:11:18.544Z] [    info] No more output from stderr
[2020-10-30T20:11:18.544Z] [    info] Customization command output: ''.

[2020-10-30T20:11:18.544Z] [   error] Customization command failed with exitcode: 127, stderr: ''.

[2020-10-30T20:11:18.544Z] [    info] cloud-init is not installed.

[2020-10-30T20:11:18.545Z] [    info] Executing traditional GOSC workflow.

[2020-10-30T20:11:18.545Z] [   debug] Command to exec : '/usr/bin/perl'.

[2020-10-30T20:11:18.545Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:18.545Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:18.545Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:19.362Z] [    info] Saving output from stdout
[2020-10-30T20:11:19.363Z] [    info] Saving output from stdout
[2020-10-30T20:11:19.363Z] [    info] Saving output from stdout
[2020-10-30T20:11:19.363Z] [    info] Saving output from stdout
[2020-10-30T20:11:19.363Z] [    info] Saving output from stdout
[2020-10-30T20:11:19.463Z] [    info] Saving output from stdout
[2020-10-30T20:11:19.564Z] [    info] Saving output from stdout
[2020-10-30T20:11:19.664Z] [    info] Saving output from stdout
[2020-10-30T20:11:20.265Z] [    info] Saving output from stdout
[2020-10-30T20:11:20.365Z] [    info] Saving output from stdout
[2020-10-30T20:11:20.467Z] [    info] Saving output from stdout
[2020-10-30T20:11:20.569Z] [    info] Saving output from stdout
[2020-10-30T20:11:20.569Z] [    info] Saving output from stdout
[2020-10-30T20:11:20.682Z] [    info] Saving output from stdout
[2020-10-30T20:11:27.542Z] [    info] Saving output from stdout
[2020-10-30T20:11:27.542Z] [    info] Saving output from stdout
[2020-10-30T20:11:27.542Z] [    info] Saving output from stdout
[2020-10-30T20:11:27.643Z] [    info] Process exited normally after 9 seconds, returned 0
[2020-10-30T20:11:27.643Z] [    info] Saving output from stdout
[2020-10-30T20:11:27.643Z] [    info] No more output from stdout
[2020-10-30T20:11:27.643Z] [    info] No more output from stderr
[2020-10-30T20:11:27.643Z] [    info] Customization command output: 'DEBUG: Creating directory /var/lock/vmware 
DEBUG: Opening /var/lock/vmware/gosc in O_CREAT|O_EXCL|O_WRONLY mode 
INFO: Opening file name /var/run/.vmware-imgcust-d8hX0vf/cust.cfg. 
DEBUG: Processing line: '[NETWORK]' 
DEBUG: FOUND CATEGORY = NETWORK 
DEBUG: Processing line: 'NETWORKING = yes' 
DEBUG: ADDED KEY-VAL :: 'NETWORK|NETWORKING' = 'yes' 
DEBUG: Processing line: 'BOOTPROTO = dhcp' 
DEBUG: ADDED KEY-VAL :: 'NETWORK|BOOTPROTO' = 'dhcp' 
DEBUG: Processing line: 'HOSTNAME = ub20test' 
DEBUG: ADDED KEY-VAL :: 'NETWORK|HOSTNAME' = 'ub20test' 
DEBUG: Processing line: 'DOMAINNAME = our.org' 
DEBUG: ADDED KEY-VAL :: 'NETWORK|DOMAINNAME' = 'our.org' 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '[NIC-CONFIG]' 
DEBUG: FOUND CATEGORY = NIC-CONFIG 
DEBUG: Processing line: 'NICS = NIC1' 
DEBUG: ADDED KEY-VAL :: 'NIC-CONFIG|NICS' = 'NIC1' 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '[NIC1]' 
DEBUG: FOUND CATEGORY = NIC1 
DEBUG: Processing line: 'MACADDR = 00:50:56:01:0f:ba' 
DEBUG: ADDED KEY-VAL :: 'NIC1|MACADDR' = '00:50:56:01:0f:ba' 
DEBUG: Processing line: 'PRIMARY = yes' 
DEBUG: ADDED KEY-VAL :: 'NIC1|PRIMARY' = 'yes' 
DEBUG: Processing line: 'ONBOOT = yes' 
DEBUG: ADDED KEY-VAL :: 'NIC1|ONBOOT' = 'yes' 
DEBUG: Processing line: 'IPv4_MODE = BACKWARDS_COMPATIBLE' 
DEBUG: ADDED KEY-VAL :: 'NIC1|IPv4_MODE' = 'BACKWARDS_COMPATIBLE' 
DEBUG: Processing line: 'BOOTPROTO = static' 
DEBUG: ADDED KEY-VAL :: 'NIC1|BOOTPROTO' = 'static' 
DEBUG: Processing line: 'IPADDR = 10.8.35.130' 
DEBUG: ADDED KEY-VAL :: 'NIC1|IPADDR' = '10.8.35.130' 
DEBUG: Processing line: 'NETMASK = 255.255.240.0' 
DEBUG: ADDED KEY-VAL :: 'NIC1|NETMASK' = '255.255.240.0' 
DEBUG: Processing line: 'GATEWAY = 10.8.32.1' 
DEBUG: ADDED KEY-VAL :: 'NIC1|GATEWAY' = '10.8.32.1' 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '[DNS]' 
DEBUG: FOUND CATEGORY = DNS 
DEBUG: Processing line: 'DNSFROMDHCP=no' 
DEBUG: ADDED KEY-VAL :: 'DNS|DNSFROMDHCP' = 'no' 
DEBUG: Processing line: 'SUFFIX|1 = our.org' 
DEBUG: ADDED KEY-VAL :: 'DNS|SUFFIX|1' = 'our.org' 
DEBUG: Processing line: 'NAMESERVER|1 = 10.20.100.53' 
DEBUG: ADDED KEY-VAL :: 'DNS|NAMESERVER|1' = '10.20.100.53' 
DEBUG: Processing line: 'NAMESERVER|2 = 10.20.200.53' 
DEBUG: ADDED KEY-VAL :: 'DNS|NAMESERVER|2' = '10.20.200.53' 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '[MISC]' 
DEBUG: FOUND CATEGORY = MISC 
DEBUG: Processing line: 'MARKER-ID=226343f8-ab74-4f97-8e8c-08711f7e4780' 
DEBUG: ADDED KEY-VAL :: 'MISC|MARKER-ID' = '226343f8-ab74-4f97-8e8c-08711f7e4780' 
DEBUG: Processing line: 'POST-GC-STATUS=yes' 
DEBUG: ADDED KEY-VAL :: 'MISC|POST-GC-STATUS' = 'yes' 
DEBUG: Processing line: 'DEFAULT-RUN-POST-CUST-SCRIPT=yes' 
DEBUG: ADDED KEY-VAL :: 'MISC|DEFAULT-RUN-POST-CUST-SCRIPT' = 'yes' 
DEBUG: Processing line: '' 
DEBUG: Empty line. Ignored. 
DEBUG: Processing line: '[PASSWORD]' 
DEBUG: FOUND CATEGORY = PASSWORD 
DEBUG: Processing line: 'RESET=no' 
DEBUG: ADDED KEY-VAL :: 'PASSWORD|RESET' = 'no' 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

DEBUG: Reading /etc/os-release file ...  
DEBUG: opening file /etc/os-release. 
DEBUG: Match found   : Line = ID=ubuntu

DEBUG: Actual String : ubuntu 
DEBUG: ID: ubuntu 
DEBUG: opening file /etc/os-release. 
DEBUG: Match found   : Line = VERSION_ID="20.04"

DEBUG: Actual String : "20.04" 
DEBUG: Version: "20.04" 
WARNING: Amazon Linux flavor not detected 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

WARNING: RedHat release file not available. Ignoring it. 
WARNING: Redhat flavor not detected 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

WARNING: RedHat release file not available. Ignoring it. 
WARNING: Redhat flavor not detected 
DEBUG: Command: 'cat /etc/lsb-release' 
DEBUG: Result: DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=20.04
DISTRIB_CODENAME=focal
DISTRIB_DESCRIPTION="Ubuntu 20.04.1 LTS"

DEBUG: Exit Code: 0 
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

INFO: Detected distribution: Ubuntu 20.04 
DEBUG: Reading issue file ...  
DEBUG: Command: 'cat /etc/issue' 
DEBUG: Result: Ubuntu 20.04.1 LTS \n \l

DEBUG: Exit Code: 0 
DEBUG: Ubuntu 20.04.1 LTS \n \l

INFO: Detected distribution flavour: Ubuntu 20.04 
INFO: Customization instance Ubuntu1910Customization loaded. 
INFO: Get Tools Daemon Command Line 
DEBUG: Command: 'ps -C vmtoolsd -o cmd=' 
DEBUG: Result: /usr/bin/vmtoolsd

DEBUG: Exit Code: 0 
DEBUG: Command: '/usr/bin/vmtoolsd --cmd "info-set guestinfo.gc.status Started"' 
DEBUG: Result: 

DEBUG: Exit Code: 0 
INFO: Customization started 
DEBUG: Command: 'hostname 2>/dev/null' 
DEBUG: Result: ub20test

DEBUG: Exit Code: 0 
DEBUG: TimedCommand: 'hostname -f 2>/dev/null' with timeout of 5 sec 
DEBUG: Fetching result from /tmp/timed_out_tmp_file_761 
DEBUG: TimedResult: ub20test.our.org

DEBUG: opening file /etc/hostname. 
DEBUG: Match found   : Line = ub20test 
DEBUG: Actual String : ub20test 
INFO: OLD HOST NAME = ub20test 
INFO: Handling pre-customization ...  
INFO: RunCustomScript invoked in '/var/run/.vmware-imgcust-d8hX0vf/' for 'precustomization' 
INFO: No customization script to run 
INFO: RunCustomScript has completed 
INFO: Customizing Network settings ...  
INFO: Erasing DHCP leases 
DEBUG: Command: 'pkill dhclient' 
DEBUG: Result:  
DEBUG: Exit Code: 256 
DEBUG: Command: 'rm -f /var/lib/dhcp/*' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
DEBUG: Check if command [hostnamectl] is available 
INFO: Check if hostnamectl is available 
DEBUG: Command: 'hostnamectl status 2>/tmp/guest.customization.stderr' 
DEBUG: Result:    Static hostname: ub20test
         Icon name: computer-vm
           Chassis: vm
        Machine ID: 7f814f3db1d44efca80152727e6c538a
           Boot ID: f12df2fbf24649f6a90bfdbad95556ac
    Virtualization: vmware
  Operating System: Ubuntu 20.04.1 LTS
            Kernel: Linux 5.4.0-26-generic
      Architecture: x86-64

DEBUG: Exit Code: 0 
DEBUG: Stderr:  
DEBUG: Set the host name to ub20test via [hostnamectl set-hostname] 
DEBUG: Command: 'hostnamectl set-hostname ub20test' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
DEBUG: Host name is ub20test 
DEBUG: opening file for writing (/etc/hostname). 
DEBUG: Command: 'chmod 644 /etc/hostname' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Customizing NICS ...  
DEBUG: Command: '/bin/cp -f /etc/netplan/01-network-manager-all.yaml /etc/netplan/01-network-manager-all.yaml.BeforeVMwareCustomization' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
DEBUG: Command: '/bin/cp -f /etc/netplan/99-netcfg-vmware.yaml /etc/netplan/99-netcfg-vmware.yaml.BeforeVMwareCustomization' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Customizing NICS. { NIC1 } 
INFO: Customizing NIC NIC1 
DEBUG: Get interface name for MAC 00:50:56:01:0f:ba, via [ip addr show] 
DEBUG: Command: 'whereis ip' 
DEBUG: Result: ip: /usr/bin/ip /usr/sbin/ip /usr/share/man/man7/ip.7.gz /usr/share/man/man8/ip.8.gz

DEBUG: Exit Code: 0 
DEBUG: Command: '/usr/bin/ip addr show' 
DEBUG: Result: 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host 
       valid_lft forever preferred_lft forever
2: ens160: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000
    link/ether 00:50:56:01:0f:ba brd ff:ff:ff:ff:ff:ff
    inet 10.8.35.129/20 brd 10.8.47.255 scope global ens160
       valid_lft forever preferred_lft forever
    inet6 fe80::250:56ff:fe01:fba/64 scope link 
       valid_lft forever preferred_lft forever

DEBUG: Exit Code: 0 
INFO: NIC suffix = ens160 
DEBUG: Checking if ens160 has static ip set in /etc/netplan/01-network-manager-all.yaml 
DEBUG: opening file /etc/netplan/01-network-manager-all.yaml. 
DEBUG: opening file for writing (/etc/netplan/01-network-manager-all.yaml). 
DEBUG: Checking if ens160 has static ip set in /etc/netplan/99-netcfg-vmware.yaml 
DEBUG: opening file /etc/netplan/99-netcfg-vmware.yaml. 
DEBUG: Removing static ip address line:       addresses:

DEBUG: Removing static ip address line:         - 10.8.35.129/20

DEBUG: opening file for writing (/etc/netplan/99-netcfg-vmware.yaml). 
INFO: Query config for ^(NIC1\|IPv6ADDR\|) 
INFO: Query config for ^(NIC1\|IPv6NETMASK\|) 
INFO: Configuring gateway from the primary NIC 'NIC1'. 
INFO: Query config for ^NIC1(\|IPv6GATEWAY\|) 
INFO: Query config for ^(DNS\|SUFFIX\|) 
DEBUG: Match Found : DNS|SUFFIX|1 
DEBUG: 0 
INFO: Query config for ^(DNS\|NAMESERVER\|) 
DEBUG: Match Found : DNS|NAMESERVER|2 
DEBUG: 0 
DEBUG: Match Found : DNS|NAMESERVER|1 
DEBUG: 1 
DEBUG: opening file for writing (/etc/netplan/99-netcfg-vmware.yaml). 
DEBUG: Command: 'chmod 644 /etc/netplan/99-netcfg-vmware.yaml' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Apply Netplan Settings 
DEBUG: Command: '/usr/sbin/netplan apply 2>&1' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Customizing Hosts file ...  
DEBUG: Old hostname=[ub20test] 
DEBUG: Old FQDN=[ub20test.our.org] 
DEBUG: New hostname=[ub20test] 
DEBUG: Building FQDN. HostnameFQDN: ub20test, Domainname: our.org 
DEBUG: New FQDN=[ub20test.our.org] 
DEBUG: opening file /etc/hosts. 
DEBUG: Line (inp): 127.0.0.1    localhost

DEBUG: Line (inp): 127.0.1.1    ub20-desk-tplt

DEBUG: Line (inp): 

DEBUG: Line (inp): # The following lines are desirable for IPv6 capable hosts

DEBUG: Line (inp): ::1     ip6-localhost ip6-loopback

DEBUG: Line (inp): fe00::0 ip6-localnet

DEBUG: Line (inp): ff00::0 ip6-mcastprefix

DEBUG: Line (inp): ff02::1 ip6-allnodes

DEBUG: Line (inp): ff02::2 ip6-allrouters

DEBUG: Line (inp): 

DEBUG: Line (inp): 

DEBUG: Line (inp): 

DEBUG: Line (inp): 

DEBUG: Line (inp): 10.8.35.129  ub20test.our.org ub20test

DEBUG: Static ip entry added 
DEBUG: Line (out): 127.0.0.1    localhost

DEBUG: Line (out): 127.0.1.1    ub20-desk-tplt

DEBUG: Line (out): 

DEBUG: Line (out): # The following lines are desirable for IPv6 capable hosts

DEBUG: Line (out): ::1     ip6-localhost ip6-loopback

DEBUG: Line (out): fe00::0 ip6-localnet

DEBUG: Line (out): ff00::0 ip6-mcastprefix

DEBUG: Line (out): ff02::1 ip6-allnodes

DEBUG: Line (out): ff02::2 ip6-allrouters

DEBUG: Line (out): 

DEBUG: Line (out): 

DEBUG: Line (out): 

DEBUG: Line (out): 

DEBUG: Line (out): 
10.8.35.130 ub20test.our.org ub20test

DEBUG: opening file for writing (/etc/hosts). 
DEBUG: Command: 'chmod 644 /etc/hosts' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Customizing DNS ...  
DEBUG: opening file /etc/nsswitch.conf. 
DEBUG: opening file for writing (/etc/nsswitch.conf). 
DEBUG: Command: 'chmod 644 /etc/nsswitch.conf' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Leave /etc/resolv.conf unchanged. 
INFO: Query config for ^(DNS\|SUFFIX\|) 
DEBUG: Match Found : DNS|SUFFIX|1 
DEBUG: 0 
DEBUG: opening file for writing (/etc/dhcp/dhclient.conf). 
DEBUG: Command: 'chmod 644 /etc/dhcp/dhclient.conf' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Query config for ^(DNS\|NAMESERVER\|) 
DEBUG: Match Found : DNS|NAMESERVER|2 
DEBUG: 0 
DEBUG: Match Found : DNS|NAMESERVER|1 
DEBUG: 1 
DEBUG: opening file for writing (/etc/dhcp/dhclient.conf). 
DEBUG: Command: 'chmod 644 /etc/dhcp/dhclient.conf' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Customizing Date&Time ...  
INFO: Handling password settings ...  
INFO: Changing password is not needed 
INFO: Handling post-customization ...  
INFO: RunCustomScript invoked in '/var/run/.vmware-imgcust-d8hX0vf/' for 'postcustomization' 
INFO: No customization script to run 
INFO: RunCustomScript has completed 
INFO: Handling marker creation ...  
DEBUG: Command: '/bin/rm -f /.markerfile-*.txt' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
DEBUG: Command: '/bin/touch /.markerfile-226343f8-ab74-4f97-8e8c-08711f7e4780.txt' 
DEBUG: Result:  
DEBUG: Exit Code: 0 
INFO: Get Tools Daemon Command Line 
DEBUG: Command: 'ps -C vmtoolsd -o cmd=' 
DEBUG: Result: /usr/bin/vmtoolsd

DEBUG: Exit Code: 0 
DEBUG: Command: '/usr/bin/vmtoolsd --cmd "info-set guestinfo.gc.status Successful"' 
DEBUG: Result: 

DEBUG: Exit Code: 0 
INFO: Customization completed. 
DEBUG: Removing lock file /var/lock/vmware/gosc. 
'.

[2020-10-30T20:11:27.643Z] [    info] No nics to enable.

[2020-10-30T20:11:27.646Z] [    info] Transitioning from state 'INPROGRESS' to state 'Done'.

[2020-10-30T20:11:27.646Z] [    info] ENTER STATE 'Done'.

[2020-10-30T20:11:27.646Z] [    info] EXIT STATE 'INPROGRESS'.

[2020-10-30T20:11:27.646Z] [    info] Deployment succeeded.

[2020-10-30T20:11:27.646Z] [    info] Launching cleanup.

[2020-10-30T20:11:27.646Z] [   debug] Command to exec : '/bin/rm'.

[2020-10-30T20:11:27.646Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:27.648Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:27.648Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:27.748Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:27.748Z] [    info] No more output from stdout
[2020-10-30T20:11:27.748Z] [    info] No more output from stderr
[2020-10-30T20:11:27.748Z] [    info] Customization command output: ''.

[2020-10-30T20:11:27.748Z] [    info] sSkipReboot: 'false', forceSkipReboot 'false'.

[2020-10-30T20:11:27.749Z] [   debug] Ran DeployPkg_DeployPackageFromFile successfully
[2020-10-30T20:11:27.749Z] [   debug] ## Closing log
[2020-10-30T20:11:27.749Z] [    info] Trigger reboot.

[2020-10-30T20:11:27.749Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:27.749Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:27.750Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:27.750Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:28.557Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:28.557Z] [    info] No more output from stdout
[2020-10-30T20:11:28.557Z] [    info] No more output from stderr
[2020-10-30T20:11:28.557Z] [    info] Customization command output: ''.

[2020-10-30T20:11:29.558Z] [    info] Rebooting.

[2020-10-30T20:11:29.558Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:29.558Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:29.558Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:29.559Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:29.659Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:29.659Z] [    info] No more output from stdout
[2020-10-30T20:11:29.659Z] [    info] No more output from stderr
[2020-10-30T20:11:29.659Z] [    info] Customization command output: ''.

[2020-10-30T20:11:30.659Z] [    info] Rebooting.

[2020-10-30T20:11:30.659Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:30.659Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:30.660Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:30.660Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:30.760Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:30.761Z] [    info] No more output from stdout
[2020-10-30T20:11:30.761Z] [    info] No more output from stderr
[2020-10-30T20:11:30.761Z] [    info] Customization command output: ''.

[2020-10-30T20:11:31.761Z] [    info] Rebooting.

[2020-10-30T20:11:31.761Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:31.761Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:31.762Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:31.762Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:31.863Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:31.863Z] [    info] No more output from stdout
[2020-10-30T20:11:31.863Z] [    info] No more output from stderr
[2020-10-30T20:11:31.863Z] [    info] Customization command output: ''.

[2020-10-30T20:11:32.863Z] [    info] Rebooting.

[2020-10-30T20:11:32.863Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:32.863Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:32.864Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:32.864Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:33.064Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:33.065Z] [    info] No more output from stdout
[2020-10-30T20:11:33.065Z] [    info] No more output from stderr
[2020-10-30T20:11:33.065Z] [    info] Customization command output: ''.

[2020-10-30T20:11:34.065Z] [    info] Rebooting.

[2020-10-30T20:11:34.065Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:34.065Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:34.066Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:34.066Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:34.466Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:34.466Z] [    info] No more output from stdout
[2020-10-30T20:11:34.466Z] [    info] No more output from stderr
[2020-10-30T20:11:34.466Z] [    info] Customization command output: ''.

[2020-10-30T20:11:35.466Z] [    info] Rebooting.

[2020-10-30T20:11:35.467Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:35.467Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:35.467Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:35.467Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:35.568Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:35.568Z] [    info] No more output from stdout
[2020-10-30T20:11:35.568Z] [    info] No more output from stderr
[2020-10-30T20:11:35.568Z] [    info] Customization command output: ''.

[2020-10-30T20:11:36.568Z] [    info] Rebooting.

[2020-10-30T20:11:36.568Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:36.568Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:36.569Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:36.569Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:36.669Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:36.670Z] [    info] No more output from stdout
[2020-10-30T20:11:36.670Z] [    info] No more output from stderr
[2020-10-30T20:11:36.670Z] [    info] Customization command output: ''.

[2020-10-30T20:11:37.670Z] [    info] Rebooting.

[2020-10-30T20:11:37.670Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:37.670Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:37.671Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:37.671Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:37.771Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:37.771Z] [    info] No more output from stdout
[2020-10-30T20:11:37.771Z] [    info] No more output from stderr
[2020-10-30T20:11:37.771Z] [    info] Customization command output: ''.

[2020-10-30T20:11:38.772Z] [    info] Rebooting.

[2020-10-30T20:11:38.772Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:38.772Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:38.772Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:38.773Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:38.873Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:38.873Z] [    info] No more output from stdout
[2020-10-30T20:11:38.873Z] [    info] No more output from stderr
[2020-10-30T20:11:38.873Z] [    info] Customization command output: ''.

[2020-10-30T20:11:39.873Z] [    info] Rebooting.

[2020-10-30T20:11:39.873Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:39.873Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:39.874Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:39.875Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:39.975Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:39.975Z] [    info] No more output from stdout
[2020-10-30T20:11:39.975Z] [    info] No more output from stderr
[2020-10-30T20:11:39.975Z] [    info] Customization command output: ''.

[2020-10-30T20:11:40.975Z] [    info] Rebooting.

[2020-10-30T20:11:40.975Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:40.975Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:40.976Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:40.976Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:41.077Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:41.077Z] [    info] No more output from stdout
[2020-10-30T20:11:41.077Z] [    info] No more output from stderr
[2020-10-30T20:11:41.077Z] [    info] Customization command output: ''.

[2020-10-30T20:11:42.077Z] [    info] Rebooting.

[2020-10-30T20:11:42.077Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:42.077Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:42.078Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:42.078Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:42.178Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:42.178Z] [    info] No more output from stdout
[2020-10-30T20:11:42.178Z] [    info] No more output from stderr
[2020-10-30T20:11:42.178Z] [    info] Customization command output: ''.

[2020-10-30T20:11:43.178Z] [    info] Rebooting.

[2020-10-30T20:11:43.179Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:43.179Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:43.180Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:43.180Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:43.281Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:43.281Z] [    info] No more output from stdout
[2020-10-30T20:11:43.281Z] [    info] No more output from stderr
[2020-10-30T20:11:43.281Z] [    info] Customization command output: ''.

[2020-10-30T20:11:44.281Z] [    info] Rebooting.

[2020-10-30T20:11:44.281Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:44.281Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:44.282Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:44.282Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:44.382Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:44.382Z] [    info] No more output from stdout
[2020-10-30T20:11:44.382Z] [    info] No more output from stderr
[2020-10-30T20:11:44.382Z] [    info] Customization command output: ''.

[2020-10-30T20:11:45.382Z] [    info] Rebooting.

[2020-10-30T20:11:45.383Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:45.383Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:45.383Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:45.383Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:45.484Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:45.484Z] [    info] No more output from stdout
[2020-10-30T20:11:45.484Z] [    info] No more output from stderr
[2020-10-30T20:11:45.484Z] [    info] Customization command output: ''.

[2020-10-30T20:11:46.484Z] [    info] Rebooting.

[2020-10-30T20:11:46.484Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:46.484Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:46.485Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:46.485Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:46.585Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:46.586Z] [    info] No more output from stdout
[2020-10-30T20:11:46.586Z] [    info] No more output from stderr
[2020-10-30T20:11:46.586Z] [    info] Customization command output: ''.

[2020-10-30T20:11:47.586Z] [    info] Rebooting.

[2020-10-30T20:11:47.586Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:47.586Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:47.587Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:47.587Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:47.687Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:47.687Z] [    info] No more output from stdout
[2020-10-30T20:11:47.688Z] [    info] No more output from stderr
[2020-10-30T20:11:47.688Z] [    info] Customization command output: ''.

[2020-10-30T20:11:48.688Z] [    info] Rebooting.

[2020-10-30T20:11:48.688Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:48.688Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:48.689Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:48.689Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:48.789Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:48.789Z] [    info] No more output from stdout
[2020-10-30T20:11:48.789Z] [    info] No more output from stderr
[2020-10-30T20:11:48.789Z] [    info] Customization command output: ''.

[2020-10-30T20:11:49.790Z] [    info] Rebooting.

[2020-10-30T20:11:49.790Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:49.790Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:49.791Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:49.791Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:49.891Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:49.891Z] [    info] No more output from stdout
[2020-10-30T20:11:49.891Z] [    info] No more output from stderr
[2020-10-30T20:11:49.891Z] [    info] Customization command output: ''.

[2020-10-30T20:11:50.891Z] [    info] Rebooting.

[2020-10-30T20:11:50.891Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:50.891Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:50.893Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:50.893Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:50.993Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:50.993Z] [    info] No more output from stdout
[2020-10-30T20:11:50.993Z] [    info] No more output from stderr
[2020-10-30T20:11:50.993Z] [    info] Customization command output: ''.

[2020-10-30T20:11:51.993Z] [    info] Rebooting.

[2020-10-30T20:11:51.993Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:51.993Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:51.994Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:51.994Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:52.094Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:52.095Z] [    info] No more output from stdout
[2020-10-30T20:11:52.095Z] [    info] No more output from stderr
[2020-10-30T20:11:52.095Z] [    info] Customization command output: ''.

[2020-10-30T20:11:53.095Z] [    info] Rebooting.

[2020-10-30T20:11:53.095Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:53.095Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:53.096Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:53.096Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:53.196Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:53.196Z] [    info] No more output from stdout
[2020-10-30T20:11:53.196Z] [    info] No more output from stderr
[2020-10-30T20:11:53.196Z] [    info] Customization command output: ''.

[2020-10-30T20:11:54.197Z] [    info] Rebooting.

[2020-10-30T20:11:54.197Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:54.197Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:54.198Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:54.198Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:54.298Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:54.298Z] [    info] No more output from stdout
[2020-10-30T20:11:54.298Z] [    info] No more output from stderr
[2020-10-30T20:11:54.298Z] [    info] Customization command output: ''.

[2020-10-30T20:11:55.298Z] [    info] Rebooting.

[2020-10-30T20:11:55.298Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:55.299Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:55.299Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:55.300Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:55.400Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:55.400Z] [    info] No more output from stdout
[2020-10-30T20:11:55.400Z] [    info] No more output from stderr
[2020-10-30T20:11:55.400Z] [    info] Customization command output: ''.

[2020-10-30T20:11:56.400Z] [    info] Rebooting.

[2020-10-30T20:11:56.400Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:56.400Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:56.401Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:56.401Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:56.501Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:56.502Z] [    info] No more output from stdout
[2020-10-30T20:11:56.502Z] [    info] No more output from stderr
[2020-10-30T20:11:56.502Z] [    info] Customization command output: ''.

[2020-10-30T20:11:57.502Z] [    info] Rebooting.

[2020-10-30T20:11:57.502Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:57.502Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:57.503Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:57.503Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:57.603Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:57.603Z] [    info] No more output from stdout
[2020-10-30T20:11:57.603Z] [    info] No more output from stderr
[2020-10-30T20:11:57.603Z] [    info] Customization command output: ''.

[2020-10-30T20:11:58.604Z] [    info] Rebooting.

[2020-10-30T20:11:58.604Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:58.604Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:58.604Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:58.604Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:58.705Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:58.705Z] [    info] No more output from stdout
[2020-10-30T20:11:58.705Z] [    info] No more output from stderr
[2020-10-30T20:11:58.705Z] [    info] Customization command output: ''.

[2020-10-30T20:11:59.705Z] [    info] Rebooting.

[2020-10-30T20:11:59.705Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:11:59.706Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:11:59.707Z] [    info] Returning, pending output from stdout
[2020-10-30T20:11:59.707Z] [    info] Returning, pending output from stderr
[2020-10-30T20:11:59.807Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:11:59.807Z] [    info] No more output from stdout
[2020-10-30T20:11:59.807Z] [    info] No more output from stderr
[2020-10-30T20:11:59.807Z] [    info] Customization command output: ''.

[2020-10-30T20:12:00.808Z] [    info] Rebooting.

[2020-10-30T20:12:00.808Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:00.808Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:00.808Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:00.808Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:00.909Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:00.909Z] [    info] No more output from stdout
[2020-10-30T20:12:00.909Z] [    info] No more output from stderr
[2020-10-30T20:12:00.909Z] [    info] Customization command output: ''.

[2020-10-30T20:12:01.909Z] [    info] Rebooting.

[2020-10-30T20:12:01.909Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:01.909Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:01.910Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:01.910Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:02.011Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:02.011Z] [    info] No more output from stdout
[2020-10-30T20:12:02.011Z] [    info] No more output from stderr
[2020-10-30T20:12:02.011Z] [    info] Customization command output: ''.

[2020-10-30T20:12:03.011Z] [    info] Rebooting.

[2020-10-30T20:12:03.011Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:03.011Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:03.012Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:03.012Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:03.112Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:03.112Z] [    info] No more output from stdout
[2020-10-30T20:12:03.112Z] [    info] No more output from stderr
[2020-10-30T20:12:03.112Z] [    info] Customization command output: ''.

[2020-10-30T20:12:04.113Z] [    info] Rebooting.

[2020-10-30T20:12:04.113Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:04.113Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:04.114Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:04.114Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:04.214Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:04.214Z] [    info] No more output from stdout
[2020-10-30T20:12:04.214Z] [    info] No more output from stderr
[2020-10-30T20:12:04.214Z] [    info] Customization command output: ''.

[2020-10-30T20:12:05.214Z] [    info] Rebooting.

[2020-10-30T20:12:05.215Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:05.215Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:05.215Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:05.216Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:05.316Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:05.316Z] [    info] No more output from stdout
[2020-10-30T20:12:05.316Z] [    info] No more output from stderr
[2020-10-30T20:12:05.316Z] [    info] Customization command output: ''.

[2020-10-30T20:12:06.316Z] [    info] Rebooting.

[2020-10-30T20:12:06.316Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:06.316Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:06.317Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:06.317Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:06.417Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:06.417Z] [    info] No more output from stdout
[2020-10-30T20:12:06.417Z] [    info] No more output from stderr
[2020-10-30T20:12:06.417Z] [    info] Customization command output: ''.

[2020-10-30T20:12:07.418Z] [    info] Rebooting.

[2020-10-30T20:12:07.418Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:07.418Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:07.419Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:07.419Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:07.519Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:07.519Z] [    info] No more output from stdout
[2020-10-30T20:12:07.519Z] [    info] No more output from stderr
[2020-10-30T20:12:07.519Z] [    info] Customization command output: ''.

[2020-10-30T20:12:08.519Z] [    info] Rebooting.

[2020-10-30T20:12:08.520Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:08.520Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:08.520Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:08.520Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:08.621Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:08.621Z] [    info] No more output from stdout
[2020-10-30T20:12:08.621Z] [    info] No more output from stderr
[2020-10-30T20:12:08.621Z] [    info] Customization command output: ''.

[2020-10-30T20:12:09.621Z] [    info] Rebooting.

[2020-10-30T20:12:09.621Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:09.621Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:09.622Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:09.622Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:09.723Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:09.723Z] [    info] No more output from stdout
[2020-10-30T20:12:09.723Z] [    info] No more output from stderr
[2020-10-30T20:12:09.723Z] [    info] Customization command output: ''.

[2020-10-30T20:12:10.723Z] [    info] Rebooting.

[2020-10-30T20:12:10.723Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:10.723Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:10.724Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:10.724Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:10.824Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:10.825Z] [    info] No more output from stdout
[2020-10-30T20:12:10.825Z] [    info] No more output from stderr
[2020-10-30T20:12:10.825Z] [    info] Customization command output: ''.

[2020-10-30T20:12:11.825Z] [    info] Rebooting.

[2020-10-30T20:12:11.825Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:11.825Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:11.826Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:11.826Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:11.926Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:11.926Z] [    info] No more output from stdout
[2020-10-30T20:12:11.926Z] [    info] No more output from stderr
[2020-10-30T20:12:11.926Z] [    info] Customization command output: ''.

[2020-10-30T20:12:12.926Z] [    info] Rebooting.

[2020-10-30T20:12:12.926Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:12.927Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:12.927Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:12.928Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:13.028Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:13.028Z] [    info] No more output from stdout
[2020-10-30T20:12:13.028Z] [    info] No more output from stderr
[2020-10-30T20:12:13.028Z] [    info] Customization command output: ''.

[2020-10-30T20:12:14.028Z] [    info] Rebooting.

[2020-10-30T20:12:14.028Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:14.028Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:14.029Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:14.029Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:14.129Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:14.130Z] [    info] No more output from stdout
[2020-10-30T20:12:14.130Z] [    info] No more output from stderr
[2020-10-30T20:12:14.130Z] [    info] Customization command output: ''.

[2020-10-30T20:12:15.130Z] [    info] Rebooting.

[2020-10-30T20:12:15.131Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:15.131Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:15.131Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:15.131Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:15.232Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:15.232Z] [    info] No more output from stdout
[2020-10-30T20:12:15.232Z] [    info] No more output from stderr
[2020-10-30T20:12:15.232Z] [    info] Customization command output: ''.

[2020-10-30T20:12:16.232Z] [    info] Rebooting.

[2020-10-30T20:12:16.232Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:16.232Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:16.234Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:16.234Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:16.335Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:16.335Z] [    info] No more output from stdout
[2020-10-30T20:12:16.335Z] [    info] No more output from stderr
[2020-10-30T20:12:16.335Z] [    info] Customization command output: ''.

[2020-10-30T20:12:17.335Z] [    info] Rebooting.

[2020-10-30T20:12:17.335Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:17.335Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:17.336Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:17.336Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:17.437Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:17.437Z] [    info] No more output from stdout
[2020-10-30T20:12:17.437Z] [    info] No more output from stderr
[2020-10-30T20:12:17.437Z] [    info] Customization command output: ''.

[2020-10-30T20:12:18.437Z] [    info] Rebooting.

[2020-10-30T20:12:18.437Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:18.437Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:18.438Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:18.438Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:18.538Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:18.538Z] [    info] No more output from stdout
[2020-10-30T20:12:18.539Z] [    info] No more output from stderr
[2020-10-30T20:12:18.539Z] [    info] Customization command output: ''.

[2020-10-30T20:12:19.539Z] [    info] Rebooting.

[2020-10-30T20:12:19.539Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:19.539Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:19.540Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:19.540Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:19.640Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:19.640Z] [    info] No more output from stdout
[2020-10-30T20:12:19.640Z] [    info] No more output from stderr
[2020-10-30T20:12:19.640Z] [    info] Customization command output: ''.

[2020-10-30T20:12:20.641Z] [    info] Rebooting.

[2020-10-30T20:12:20.641Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:20.641Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:20.641Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:20.642Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:20.742Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:20.742Z] [    info] No more output from stdout
[2020-10-30T20:12:20.742Z] [    info] No more output from stderr
[2020-10-30T20:12:20.742Z] [    info] Customization command output: ''.

[2020-10-30T20:12:21.742Z] [    info] Rebooting.

[2020-10-30T20:12:21.742Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:21.742Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:21.743Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:21.743Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:21.843Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:21.843Z] [    info] No more output from stdout
[2020-10-30T20:12:21.843Z] [    info] No more output from stderr
[2020-10-30T20:12:21.843Z] [    info] Customization command output: ''.

[2020-10-30T20:12:22.844Z] [    info] Rebooting.

[2020-10-30T20:12:22.844Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:22.844Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:22.845Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:22.845Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:22.945Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:22.945Z] [    info] No more output from stdout
[2020-10-30T20:12:22.945Z] [    info] No more output from stderr
[2020-10-30T20:12:22.945Z] [    info] Customization command output: ''.

[2020-10-30T20:12:23.946Z] [    info] Rebooting.

[2020-10-30T20:12:23.946Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:23.946Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:23.947Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:23.947Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:24.047Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:24.047Z] [    info] No more output from stdout
[2020-10-30T20:12:24.047Z] [    info] No more output from stderr
[2020-10-30T20:12:24.047Z] [    info] Customization command output: ''.

[2020-10-30T20:12:25.047Z] [    info] Rebooting.

[2020-10-30T20:12:25.048Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:25.048Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:25.049Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:25.049Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:25.149Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:25.149Z] [    info] No more output from stdout
[2020-10-30T20:12:25.149Z] [    info] No more output from stderr
[2020-10-30T20:12:25.149Z] [    info] Customization command output: ''.

[2020-10-30T20:12:26.150Z] [    info] Rebooting.

[2020-10-30T20:12:26.150Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:26.150Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:26.150Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:26.150Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:26.251Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:26.251Z] [    info] No more output from stdout
[2020-10-30T20:12:26.251Z] [    info] No more output from stderr
[2020-10-30T20:12:26.251Z] [    info] Customization command output: ''.

[2020-10-30T20:12:27.251Z] [    info] Rebooting.

[2020-10-30T20:12:27.251Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:27.251Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:27.252Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:27.252Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:27.352Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:27.352Z] [    info] No more output from stdout
[2020-10-30T20:12:27.352Z] [    info] No more output from stderr
[2020-10-30T20:12:27.352Z] [    info] Customization command output: ''.

[2020-10-30T20:12:28.353Z] [    info] Rebooting.

[2020-10-30T20:12:28.353Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:28.353Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:28.353Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:28.353Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:28.454Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:28.454Z] [    info] No more output from stdout
[2020-10-30T20:12:28.454Z] [    info] No more output from stderr
[2020-10-30T20:12:28.454Z] [    info] Customization command output: ''.

[2020-10-30T20:12:29.454Z] [    info] Rebooting.

[2020-10-30T20:12:29.454Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:29.455Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:29.455Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:29.455Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:29.624Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:29.624Z] [    info] No more output from stdout
[2020-10-30T20:12:29.624Z] [    info] No more output from stderr
[2020-10-30T20:12:29.624Z] [    info] Customization command output: ''.

[2020-10-30T20:12:30.625Z] [    info] Rebooting.

[2020-10-30T20:12:30.625Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:30.625Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:30.626Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:30.626Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:30.726Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:30.726Z] [    info] No more output from stdout
[2020-10-30T20:12:30.726Z] [    info] No more output from stderr
[2020-10-30T20:12:30.726Z] [    info] Customization command output: ''.

[2020-10-30T20:12:31.726Z] [    info] Rebooting.

[2020-10-30T20:12:31.727Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:31.727Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:31.728Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:31.728Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:31.828Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:31.828Z] [    info] No more output from stdout
[2020-10-30T20:12:31.828Z] [    info] No more output from stderr
[2020-10-30T20:12:31.828Z] [    info] Customization command output: ''.

[2020-10-30T20:12:32.829Z] [    info] Rebooting.

[2020-10-30T20:12:32.829Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:32.829Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:32.830Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:32.830Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:32.930Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:32.930Z] [    info] No more output from stdout
[2020-10-30T20:12:32.930Z] [    info] No more output from stderr
[2020-10-30T20:12:32.930Z] [    info] Customization command output: ''.

[2020-10-30T20:12:33.931Z] [    info] Rebooting.

[2020-10-30T20:12:33.931Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:33.931Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:33.932Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:33.932Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:34.032Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:34.032Z] [    info] No more output from stdout
[2020-10-30T20:12:34.032Z] [    info] No more output from stderr
[2020-10-30T20:12:34.032Z] [    info] Customization command output: ''.

[2020-10-30T20:12:35.032Z] [    info] Rebooting.

[2020-10-30T20:12:35.033Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:35.033Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:35.033Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:35.034Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:35.134Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:35.134Z] [    info] No more output from stdout
[2020-10-30T20:12:35.134Z] [    info] No more output from stderr
[2020-10-30T20:12:35.134Z] [    info] Customization command output: ''.

[2020-10-30T20:12:36.134Z] [    info] Rebooting.

[2020-10-30T20:12:36.134Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:36.134Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:36.135Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:36.135Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:36.235Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:36.235Z] [    info] No more output from stdout
[2020-10-30T20:12:36.235Z] [    info] No more output from stderr
[2020-10-30T20:12:36.235Z] [    info] Customization command output: ''.

[2020-10-30T20:12:37.236Z] [    info] Rebooting.

[2020-10-30T20:12:37.236Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:37.236Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:37.237Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:37.237Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:37.337Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:37.337Z] [    info] No more output from stdout
[2020-10-30T20:12:37.337Z] [    info] No more output from stderr
[2020-10-30T20:12:37.337Z] [    info] Customization command output: ''.

[2020-10-30T20:12:38.337Z] [    info] Rebooting.

[2020-10-30T20:12:38.337Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:38.337Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:38.338Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:38.339Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:38.443Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:38.443Z] [    info] No more output from stdout
[2020-10-30T20:12:38.443Z] [    info] No more output from stderr
[2020-10-30T20:12:38.443Z] [    info] Customization command output: ''.

[2020-10-30T20:12:39.444Z] [    info] Rebooting.

[2020-10-30T20:12:39.444Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:39.444Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:39.445Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:39.445Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:39.546Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:39.546Z] [    info] No more output from stdout
[2020-10-30T20:12:39.546Z] [    info] No more output from stderr
[2020-10-30T20:12:39.546Z] [    info] Customization command output: ''.

[2020-10-30T20:12:40.546Z] [    info] Rebooting.

[2020-10-30T20:12:40.546Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:40.546Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:40.547Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:40.547Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:40.647Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:40.647Z] [    info] No more output from stdout
[2020-10-30T20:12:40.647Z] [    info] No more output from stderr
[2020-10-30T20:12:40.647Z] [    info] Customization command output: ''.

[2020-10-30T20:12:41.648Z] [    info] Rebooting.

[2020-10-30T20:12:41.648Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:41.648Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:41.649Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:41.649Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:41.749Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:41.750Z] [    info] No more output from stdout
[2020-10-30T20:12:41.750Z] [    info] No more output from stderr
[2020-10-30T20:12:41.750Z] [    info] Customization command output: ''.

[2020-10-30T20:12:42.750Z] [    info] Rebooting.

[2020-10-30T20:12:42.750Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:42.750Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:42.751Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:42.751Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:42.851Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:42.851Z] [    info] No more output from stdout
[2020-10-30T20:12:42.851Z] [    info] No more output from stderr
[2020-10-30T20:12:42.851Z] [    info] Customization command output: ''.

[2020-10-30T20:12:43.852Z] [    info] Rebooting.

[2020-10-30T20:12:43.852Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:43.852Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:43.852Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:43.853Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:43.953Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:43.953Z] [    info] No more output from stdout
[2020-10-30T20:12:43.953Z] [    info] No more output from stderr
[2020-10-30T20:12:43.953Z] [    info] Customization command output: ''.

[2020-10-30T20:12:44.953Z] [    info] Rebooting.

[2020-10-30T20:12:44.953Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:44.953Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:44.954Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:44.954Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:45.054Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:45.055Z] [    info] No more output from stdout
[2020-10-30T20:12:45.055Z] [    info] No more output from stderr
[2020-10-30T20:12:45.055Z] [    info] Customization command output: ''.

[2020-10-30T20:12:46.069Z] [    info] Rebooting.

[2020-10-30T20:12:46.069Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:46.069Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:46.070Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:46.070Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:46.170Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:46.170Z] [    info] No more output from stdout
[2020-10-30T20:12:46.170Z] [    info] No more output from stderr
[2020-10-30T20:12:46.170Z] [    info] Customization command output: ''.

[2020-10-30T20:12:47.171Z] [    info] Rebooting.

[2020-10-30T20:12:47.171Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:47.171Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:47.171Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:47.171Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:47.273Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:47.273Z] [    info] No more output from stdout
[2020-10-30T20:12:47.273Z] [    info] No more output from stderr
[2020-10-30T20:12:47.273Z] [    info] Customization command output: ''.

[2020-10-30T20:12:48.273Z] [    info] Rebooting.

[2020-10-30T20:12:48.274Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:48.274Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:48.274Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:48.274Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:48.375Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:48.375Z] [    info] No more output from stdout
[2020-10-30T20:12:48.375Z] [    info] No more output from stderr
[2020-10-30T20:12:48.375Z] [    info] Customization command output: ''.

[2020-10-30T20:12:49.375Z] [    info] Rebooting.

[2020-10-30T20:12:49.375Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:49.375Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:49.376Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:49.376Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:49.477Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:49.477Z] [    info] No more output from stdout
[2020-10-30T20:12:49.477Z] [    info] No more output from stderr
[2020-10-30T20:12:49.477Z] [    info] Customization command output: ''.

[2020-10-30T20:12:50.478Z] [    info] Rebooting.

[2020-10-30T20:12:50.478Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:50.478Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:50.479Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:50.479Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:50.579Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:50.579Z] [    info] No more output from stdout
[2020-10-30T20:12:50.579Z] [    info] No more output from stderr
[2020-10-30T20:12:50.579Z] [    info] Customization command output: ''.

[2020-10-30T20:12:51.580Z] [    info] Rebooting.

[2020-10-30T20:12:51.580Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:51.580Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:51.581Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:51.581Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:51.681Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:51.681Z] [    info] No more output from stdout
[2020-10-30T20:12:51.681Z] [    info] No more output from stderr
[2020-10-30T20:12:51.681Z] [    info] Customization command output: ''.

[2020-10-30T20:12:52.682Z] [    info] Rebooting.

[2020-10-30T20:12:52.682Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:52.682Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:52.683Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:52.683Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:52.783Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:52.784Z] [    info] No more output from stdout
[2020-10-30T20:12:52.784Z] [    info] No more output from stderr
[2020-10-30T20:12:52.784Z] [    info] Customization command output: ''.

[2020-10-30T20:12:53.784Z] [    info] Rebooting.

[2020-10-30T20:12:53.784Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:53.784Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:53.785Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:53.785Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:53.886Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:53.886Z] [    info] No more output from stdout
[2020-10-30T20:12:53.886Z] [    info] No more output from stderr
[2020-10-30T20:12:53.886Z] [    info] Customization command output: ''.

[2020-10-30T20:12:54.886Z] [    info] Rebooting.

[2020-10-30T20:12:54.886Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:54.886Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:54.887Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:54.887Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:55.087Z] [    info] Process exited normally after 0 seconds, returned 0
[2020-10-30T20:12:55.088Z] [    info] No more output from stdout
[2020-10-30T20:12:55.088Z] [    info] No more output from stderr
[2020-10-30T20:12:55.088Z] [    info] Customization command output: ''.

[2020-10-30T20:12:55.318Z] [    info] Rebooting.

[2020-10-30T20:12:55.318Z] [   debug] Command to exec : '/sbin/telinit'.

[2020-10-30T20:12:55.318Z] [    info] sizeof ProcessInternal is 56

[2020-10-30T20:12:55.319Z] [    info] Returning, pending output from stdout
[2020-10-30T20:12:55.319Z] [    info] Returning, pending output from stderr
[2020-10-30T20:12:55.419Z] [    info] Process exited normally after 0 seconds, returned 1
[2020-10-30T20:12:55.419Z] [    info] No more output from stdout
[2020-10-30T20:12:55.419Z] [    info] Saving output from stderr
[2020-10-30T20:12:55.419Z] [    info] No more output from stderr
[2020-10-30T20:12:55.419Z] [    info] Customization command output: ''.

[2020-10-30T20:12:55.419Z] [   error] Customization command failed with exitcode: 1, stderr: 'Failed to connect to bus: Connection refused
Failed to open initctl fifo: No such device or address
Failed to talk to init daemon.
'.

[2020-10-30T20:12:56.420Z] [    info] Reboot has been triggered.

[2020-10-30T20:12:56.420Z] [   debug] Ran DeployPkg_DeployPackageFromFile successfully
[2020-10-30T20:12:56.420Z] [   debug] ## Closing log

PengpengSun commented 3 years ago

Hi Jeff,

INFO: Detected distribution flavour: Ubuntu 20.04 Yes, the correct Ubuntu version was detected with VCD 10.1.2.

DEBUG: Processing line: 'HOSTNAME = ub20test' DEBUG: ADDED KEY-VAL :: 'NETWORK|HOSTNAME' = 'ub20test' And the hostname customization looks good to me, according to above log, the vm hostname was requested to be customized to 'ub20test'. Could you please double-check if new hostname is set correctly for the VM customization?

For the looping, customization script calls a command to reboot VM in a loop. But the vm took 1 minute and 29 seconds to start reboot from [2020-10-30T20:11:27.749Z] to [2020-10-30T20:12:56.420Z], so many logs printed.

jblaine commented 3 years ago

Yes, the hostname typed into the wizard the other day, every step of the way, was ub20test5.

I haven't used just "ub20test" as a test hostname in 2 months.

PengpengSun commented 3 years ago

Hi Jeff,

I think you have double-checked the wizard input and reproduced the same, then I suggest you collect the vCD logs(see: https://kb.vmware.com/s/article/1026312) plus above customization log to file a SR request to VMware Support.

stanguturi commented 3 years ago

INFO: Detected distribution flavour: Ubuntu 20.04 Yes, the correct Ubuntu version was detected with VCD 10.1.2.

As mentioned above, the latest version of VCD properly detected the Ubuntu 20.04.

DEBUG: Processing line: 'HOSTNAME = ub20test' DEBUG: ADDED KEY-VAL :: 'NETWORK|HOSTNAME' = 'ub20test'

The hostname was also properly configured.

For the looping, customization script calls a command to reboot VM in a loop. But the vm took 1 minute and 29 seconds to start reboot from [2020-10-30T20:11:27.749Z] to [2020-10-30T20:12:56.420Z], so many logs printed.

Ignore the above messages.

then I suggest you collect the vCD logs(see: https://kb.vmware.com/s/article/1026312) plus above customization log to file a SR request to VMware Support.

As @PengpengSun suggested, please open a SR with VMware support team to investigate the VCD issue. Not really an issue with open-vm-tools. Closing. Thanks.

vmware / open-vm-tools

Customization on Ubuntu 20.04 not working (vCenter Server Appliance version 6.7u3j) #479