# Standard module
import logging
import re
-import random
import time
import datetime
-import socket
-import textwrap
import signal
import tempfile
import os
# Third party modules
import pytz
-import paramiko
from pyVmomi import vim
-from fb_tools.common import pp, to_str
-from fb_tools.errors import HandlerError, ExpectedHandlerError
+from fb_tools.common import pp
+from fb_tools.errors import HandlerError
from fb_tools.handler import BaseHandler
from fb_vmware.errors import VSphereExpectedError
from ..xlate import XLATOR
-__version__ = '2.4.6'
+__version__ = '2.4.7'
LOG = logging.getLogger(__name__)
TZ = pytz.timezone('Europe/Berlin')
return 0
- # -------------------------------------------------------------------------
- def wait_for_finish_install(self):
-
- LOG.info(_("Waiting for finishing installation ..."))
-
- LOG.debug(_("Waiting initially for {} seconds:").format(self.initial_sleep))
- print(' ==> ', end='', flush=True)
-
- cur_time = time.time()
- cur_duration = cur_time - self.ts_start_install
- last_dot = cur_time
-
- while cur_duration <= self.initial_sleep:
- time.sleep(self.interval_poll)
- cur_time = time.time()
- if (cur_time - last_dot) >= self.interval_dot:
- print('.', end='', flush=True)
- last_dot = cur_time
- cur_duration = cur_time - self.ts_start_install
- print('', flush=True)
-
- LOG.debug(_("Waiting for SSH available ..."))
-
- addr_infos = {}
- for ip in self.tpl_ips:
- ai = socket.getaddrinfo(ip, 22, socket.AF_INET, socket.SOCK_STREAM)
- if self.verbose > 1:
- msg = _("Got following address_infos for {h!r}, IPv4 TCP port {p}:").format(
- h=ip, p=22)
- msg += '\n' + pp(ai)
- LOG.debug(msg)
- if not ai:
- raise HandlerError(_(
- "Did not get address infos for {h!r}, IPv4 TCP port {p}.").format(
- h=ip, p=22))
-
- addr_info = random.choice(ai)
- LOG.debug(_("Using address info: {}").format(pp(addr_info)))
- addr_infos[ip] = addr_info
-
- if self.verbose <= 3:
- print(' ==> ', end='', flush=True)
-
- ssh_available = False
- cur_duration = cur_time - self.ts_start_install
- cur_time = time.time()
- last_dot = cur_time
- i = 0
- first = True
- while not ssh_available and cur_duration <= self.cfg.max_wait_for_finish_install:
-
- if not first:
- time.sleep(self.interval_poll)
- else:
- first = False
-
- cur_time = time.time()
- cur_duration = cur_time - self.ts_start_install
- if (self.verbose <= 3) and ((cur_time - last_dot) >= self.interval_dot):
- print('.', end='', flush=True)
- i += 1
- if i >= 60:
- print('', flush=True)
- print(' ', end='', flush=True)
- i = 0
- last_dot = cur_time
-
- for ip in addr_infos.keys():
-
- addr_info = addr_infos[ip]
- if self.check_ssh_available(addr_info):
- ssh_available = True
- self.tpl_ip = ip
- break
-
- if not ssh_available:
- continue
-
- if self.verbose <= 3:
- print('', flush=True)
- self.ts_finish_install = time.time()
-
- self.ts_finish_install = time.time()
- duration = self.ts_finish_install - self.ts_start_install
- minutes = int(int(duration) / 60)
- seconds = duration - float(minutes * 60)
-
- LOG.info(_("Needed {m} minutes and {s:0.1f} seconds.").format(
- m=minutes, s=seconds))
-
- if not ssh_available:
- raise ExpectedHandlerError(
- _("SSH not available after {:0.1f} seconds, giving up.").format(duration))
-
- # -------------------------------------------------------------------------
- def check_ssh_available(self, addr_info):
-
- family, socktype, proto, canonname, sockaddr = addr_info
-
- if self.verbose > 3:
- LOG.debug(_("Trying to connect to {a} via TCP port {p} ...").format(
- a=sockaddr[0], p=sockaddr[1]))
-
- try:
- sock = socket.socket(family, socktype, proto)
- except socket.error as e:
- sock = None
- LOG.warn(_("Error creating socket: {}").format(e))
- return False
-
- try:
- sock.connect(sockaddr)
- except socket.error as e:
- sock.close()
- sock = None
- if self.verbose > 3:
- LOG.debug(_("Could not connect: {}").format(e))
- return False
-
- LOG.info(_("Connected to {a} via TCP port {p}.").format(
- a=sockaddr[0], p=sockaddr[1]))
-
- data = sock.recv(4096)
- if data:
- msg = to_str(data).strip()
- LOG.info(_("Got SSHD banner: {}").format(msg))
-
- sock.close()
- sock = None
-
- return True
-
- # -------------------------------------------------------------------------
- def exec_remote(self, cmd, strict_host_key_checking=False):
-
- ssh = None
- result = {'out': None, 'err': None}
- if strict_host_key_checking:
- policy = paramiko.client.AutoAddPolicy()
- else:
- policy = paramiko.client.MissingHostKeyPolicy()
-
- try:
-
- LOG.debug(_("Initializing {} ...").format('paramiko SSHClient'))
- ssh = paramiko.SSHClient()
- LOG.debug(_("Loading SSH system host keys."))
- ssh.load_system_host_keys()
- LOG.debug(_("Setting SSH missing host key policy to {}.").format(
- policy.__class__.__name__))
- ssh.set_missing_host_key_policy(policy)
-
- LOG.debug(_("Connecting to {h!r}, port {p} as {u!r} per SSH ...").format(
- h=self.tpl_ip, p=self.ssh_port, u=self.ssh_user))
- ssh.connect(
- self.tpl_ip, port=self.ssh_port, timeout=self.ssh_timeout,
- username=self.ssh_user, key_filename=self.private_ssh_key)
-
- if self.verbose > 1:
- LOG.debug(_("Commands to execute:") + '\n' + cmd)
-
- stdin, stdout, stderr = ssh.exec_command(
- cmd, timeout=self.ssh_timeout)
-
- result['out'] = to_str(stdout.read()).strip()
- result['err'] = to_str(stderr.read()).strip()
-
- LOG.debug(_("Output on {}:").format('STDERR') + '\n' + result['err'])
-
- finally:
- if ssh:
- if self.verbose > 2:
- LOG.debug(_("Closing SSH connection."))
- ssh.close()
-
- return result
-
- # -------------------------------------------------------------------------
- def show_install_log(self):
-
- LOG.info(_("Showing post install log ..."))
- install_logfile = '/var/log/anaconda/post-install.log'
-
- cmd = textwrap.dedent("""\
- if [ -f {log} ] ; then
- echo "-----------------------------------------------------------"
- cat {log}
- echo "-----------------------------------------------------------"
- echo
- else
- echo "Post install log {log} not found!" >&2
- fi
-
- """).format(log=install_logfile)
-
- result = self.exec_remote(cmd)
-
- if result['err']:
- LOG.error(result['err'])
- if self.postinstall_errors:
- self.postinstall_errors += result['err']
- else:
- self.postinstall_errors = result['err']
- else:
- LOG.debug("Post install log:\n\n" + result['out'])
-
- # -------------------------------------------------------------------------
- def get_postinstall_error(self):
-
- LOG.info(_("Trying to get possible post-installation errors ..."))
-
- cmd = textwrap.dedent("""\
- if [ -f /root/postinst-error.txt ] ; then
- cat /root/postinst-error.txt
- fi
- """)
-
- result = self.exec_remote(cmd)
- if result['out']:
- if self.postinstall_errors:
- self.postinstall_errors += result['out']
- else:
- self.postinstall_errors = result['out']
- LOG.error(_("Got postinstall errors:") + '\n' + result['out'])
- else:
- LOG.info(_("No postinstall errors found."))
-
- if self.postinstall_errors:
- LOG.warn(_("Template VM {!r} has to be removed.").format(self.tpl_ip))
-
- # -------------------------------------------------------------------------
- def post_install_tasks_ssh(self):
-
- LOG.info(_("Executing tasks per SSH after installation ..."))
- print_section_start('post_install_tasks', 'Exec post install tasks ...', collapsed=True)
-
- logfiles = (
- '/var/log/boot.log',
- '/var/log/cron',
- '/var/log/dnf*.log',
- '/var/log/hawkey.log',
- '/var/log/messages',
- '/var/log/secure',
- '/var/log/wtmp',
- '/var/log/vmware-*.log*',
- '/var/log/yum*.log',
- )
-
- cmd = textwrap.dedent("""\
- printf "Current host FQDN: "
- hostname -f
-
- for ks_cfg in "/root/original-ks.cfg" "/root/anaconda-ks.cfg" ; do
- echo
- echo "-----------------------------------------------------------"
- if [ -f "${ks_cfg}" ] ; then
- echo "Moving ${ks_cfg} => /var/log/anaconda/ ..."
- mv -v "${ks_cfg}" /var/log/anaconda/
- else
- echo "File ${ks_cfg} not found." >&2
- fi
- done
-
- for f in @@@LOGFILES@@@ ; do
- if [ -f "${f}" ] ; then
- echo "Truncating ${f} ..."
- cp /dev/null "${f}"
- fi
- done
-
- echo
- echo "-----------------------------------------------------------"
- echo "Current network configuration:"
- echo
- /usr/sbin/ip address show
- echo
- echo "Current routing configuration:"
- echo
- /usr/sbin/ip route show
- echo
-
- """).replace('@@@LOGFILES@@@', ' '.join(logfiles))
-
- result = self.exec_remote(cmd)
- LOG.debug(_("Output on {}:").format('STDOUT') + '\n' + result['out'])
- if not result['err']:
- LOG.debug(_("No output on {}.").format('STDERR'))
-
- print_section_end('post_install_tasks')
-
- if result['err']:
- LOG.warn(_("Output on {}:").format('STDERR') + '\n' + result['err'])
-
- # -------------------------------------------------------------------------
- def poweroff_vm(self):
-
- wait_for_shutdown = 15
-
- LOG.info(_("Waiting for {} seconds before shutting down:").format(wait_for_shutdown))
- print(' ==> ', end='', flush=True)
-
- start_waiting = time.time()
- cur_time = start_waiting
- cur_duration = 0
- last_dot = cur_time
-
- i = 0
- while cur_duration <= wait_for_shutdown:
- time.sleep(0.1)
- cur_time = time.time()
- if (cur_time - last_dot) >= 1:
- print('.', end='', flush=True)
- last_dot = cur_time
- i += 1
- if not i % 60:
- print('\n ', end='', flush=True)
- cur_duration = cur_time - start_waiting
- print('', flush=True)
-
- LOG.info(_("Last actions before powering off VM {!r} ...").format(self.tpl_ip))
-
- cmd = textwrap.dedent("""\
- echo
- echo "-----------------------------------------------------------"
- echo "Cleaning up /root/.ssh/authorized_keys ..."
- afile="/root/.ssh/authorized_keys"
- tfile="/tmp/authorized_keys"
- pattern="create-vmware-tpl@pixelpark.com"
-
- cat "${afile}" | grep -v "${pattern}" > "${tfile}"
- mv -v "${tfile}" "${afile}"
-
- echo
- echo "-----------------------------------------------------------"
- echo "Removing SSH host keys ..."
- rm -v /etc/ssh/ssh_host_*
-
- echo
- echo "Sleeping some seconds ..."
- sleep 3
-
- echo
- echo "-----------------------------------------------------------"
- echo "Powering off ..."
- poweroff && logout
-
- """)
-
- vm = self.get_temp_tpl_vm()
- power_state = vm.runtime.powerState
- LOG.debug(_("Current state of template VM is {!r}").format(power_state))
- if power_state.strip().lower() == "poweredoff":
- LOG.info(_("Template VM is already shut off."))
- return
-
- if power_state.strip().lower() != "poweredon":
- raise ExpectedHandlerError(
- _("Cannot shut down VM {h!r}, is currently in state {s!r}.").format(
- h=self.tpl_ip, s=power_state))
-
- LOG.info(_("Powering off VM {!r} per SSH ...").format(self.tpl_ip))
- print_section_start('poweroff', 'Powering off VM ...', collapsed=True)
- result = self.exec_remote(cmd)
-
- LOG.debug(_("Output on {}:").format('STDOUT') + '\n' + result['out'])
- if not result['err']:
- LOG.debug(_("No output on {}.").format('STDERR'))
-
- print_section_end('poweroff')
-
- if result['err']:
- LOG.warn(_("Output on {}:").format('STDERR') + '\n' + result['err'])
-
- cur_diff = 0
- start_shutdown = time.time()
- cur_time = start_shutdown
- last_dot = cur_time
- i = 0
-
- LOG.debug(_("Waiting for successful shut down of VM ..."))
- if self.verbose <= 3:
- print(' ==> ', end='', flush=True)
- if self.verbose > 3:
- LOG.debug(_("Current state of template VM is {!r}").format(power_state))
-
- while power_state.strip().lower() != "poweredoff":
-
- time.sleep(0.2)
-
- dot = '.'
- if power_state.lower().strip() != 'poweredon':
- dot = 'S'
-
- cur_time = time.time()
- cur_diff = cur_time - start_shutdown
- if (self.verbose <= 3) and ((cur_time - last_dot) >= self.interval_dot):
- print(dot, end='', flush=True)
- i += 1
- if i >= 60:
- print('', flush=True)
- print(' ', end='', flush=True)
- i = 0
- last_dot = cur_time
-
- vm = self.get_temp_tpl_vm()
- power_state = vm.runtime.powerState
- if self.verbose > 3:
- LOG.debug(_(
- "Still waiting for completing shutdown, current state is {!r}.").format(
- power_state))
- if power_state.strip().lower() == "poweredoff":
- print('', flush=True)
- LOG.info(_(
- "Template VM {h!r} was shutting down in {t:0.1f} seconds.").format(
- h=self.tpl_ip, t=cur_diff))
- return
- if cur_diff >= self.cfg.max_wait_for_shutdown_vm:
- break
-
- print('', flush=True)
- raise ExpectedHandlerError(_(
- "VM {h!r} was not shut down after {t:0.1f} seconds, current state is {s!r}.").format(
- h=self.tpl_ip, t=cur_diff, s=power_state))
-
# -------------------------------------------------------------------------
def create_root_authkeys(self):
# Standard modules
import logging
+import random
+import socket
+import textwrap
+import time
# Third party modules
-# from fb_tools.common import pp
-# from fb_tools.errors import HandlerError, ExpectedHandlerError
+import paramiko
+
+from fb_tools.common import pp, to_str
+from fb_tools.errors import HandlerError, ExpectedHandlerError
# Own modules
-# from .. import print_section_start, print_section_end
+from .. import print_section_start, print_section_end
from ..xlate import XLATOR
-__version__ = '0.1.0'
+__version__ = '0.2.0'
LOG = logging.getLogger(__name__)
A mixin class for extending the CrTplHandler class for VMware/VSphere dependend methods.
"""
- pass
+ # -------------------------------------------------------------------------
+ def wait_for_finish_install(self):
+
+ LOG.info(_("Waiting for finishing installation ..."))
+
+ LOG.debug(_("Waiting initially for {} seconds:").format(self.initial_sleep))
+ print(' ==> ', end='', flush=True)
+
+ cur_time = time.time()
+ cur_duration = cur_time - self.ts_start_install
+ last_dot = cur_time
+
+ while cur_duration <= self.initial_sleep:
+ time.sleep(self.interval_poll)
+ cur_time = time.time()
+ if (cur_time - last_dot) >= self.interval_dot:
+ print('.', end='', flush=True)
+ last_dot = cur_time
+ cur_duration = cur_time - self.ts_start_install
+ print('', flush=True)
+
+ LOG.debug(_("Waiting for SSH available ..."))
+
+ addr_infos = {}
+ for ip in self.tpl_ips:
+ ai = socket.getaddrinfo(ip, 22, socket.AF_INET, socket.SOCK_STREAM)
+ if self.verbose > 1:
+ msg = _("Got following address_infos for {h!r}, IPv4 TCP port {p}:").format(
+ h=ip, p=22)
+ msg += '\n' + pp(ai)
+ LOG.debug(msg)
+ if not ai:
+ raise HandlerError(_(
+ "Did not get address infos for {h!r}, IPv4 TCP port {p}.").format(
+ h=ip, p=22))
+
+ addr_info = random.choice(ai)
+ LOG.debug(_("Using address info: {}").format(pp(addr_info)))
+ addr_infos[ip] = addr_info
+
+ if self.verbose <= 3:
+ print(' ==> ', end='', flush=True)
+
+ ssh_available = False
+ cur_duration = cur_time - self.ts_start_install
+ cur_time = time.time()
+ last_dot = cur_time
+ i = 0
+ first = True
+ while not ssh_available and cur_duration <= self.cfg.max_wait_for_finish_install:
+
+ if not first:
+ time.sleep(self.interval_poll)
+ else:
+ first = False
+
+ cur_time = time.time()
+ cur_duration = cur_time - self.ts_start_install
+ if (self.verbose <= 3) and ((cur_time - last_dot) >= self.interval_dot):
+ print('.', end='', flush=True)
+ i += 1
+ if i >= 60:
+ print('', flush=True)
+ print(' ', end='', flush=True)
+ i = 0
+ last_dot = cur_time
+
+ for ip in addr_infos.keys():
+
+ addr_info = addr_infos[ip]
+ if self.check_ssh_available(addr_info):
+ ssh_available = True
+ self.tpl_ip = ip
+ break
+
+ if not ssh_available:
+ continue
+
+ if self.verbose <= 3:
+ print('', flush=True)
+ self.ts_finish_install = time.time()
+
+ self.ts_finish_install = time.time()
+ duration = self.ts_finish_install - self.ts_start_install
+ minutes = int(int(duration) / 60)
+ seconds = duration - float(minutes * 60)
+
+ LOG.info(_("Needed {m} minutes and {s:0.1f} seconds.").format(
+ m=minutes, s=seconds))
+
+ if not ssh_available:
+ raise ExpectedHandlerError(
+ _("SSH not available after {:0.1f} seconds, giving up.").format(duration))
+
+ # -------------------------------------------------------------------------
+ def check_ssh_available(self, addr_info):
+
+ family, socktype, proto, canonname, sockaddr = addr_info
+
+ if self.verbose > 3:
+ LOG.debug(_("Trying to connect to {a} via TCP port {p} ...").format(
+ a=sockaddr[0], p=sockaddr[1]))
+
+ try:
+ sock = socket.socket(family, socktype, proto)
+ except socket.error as e:
+ sock = None
+ LOG.warn(_("Error creating socket: {}").format(e))
+ return False
+
+ try:
+ sock.connect(sockaddr)
+ except socket.error as e:
+ sock.close()
+ sock = None
+ if self.verbose > 3:
+ LOG.debug(_("Could not connect: {}").format(e))
+ return False
+
+ LOG.info(_("Connected to {a} via TCP port {p}.").format(
+ a=sockaddr[0], p=sockaddr[1]))
+
+ data = sock.recv(4096)
+ if data:
+ msg = to_str(data).strip()
+ LOG.info(_("Got SSHD banner: {}").format(msg))
+
+ sock.close()
+ sock = None
+
+ return True
+
+ # -------------------------------------------------------------------------
+ def exec_remote(self, cmd, strict_host_key_checking=False):
+
+ ssh = None
+ result = {'out': None, 'err': None}
+ if strict_host_key_checking:
+ policy = paramiko.client.AutoAddPolicy()
+ else:
+ policy = paramiko.client.MissingHostKeyPolicy()
+
+ try:
+
+ LOG.debug(_("Initializing {} ...").format('paramiko SSHClient'))
+ ssh = paramiko.SSHClient()
+ LOG.debug(_("Loading SSH system host keys."))
+ ssh.load_system_host_keys()
+ LOG.debug(_("Setting SSH missing host key policy to {}.").format(
+ policy.__class__.__name__))
+ ssh.set_missing_host_key_policy(policy)
+
+ LOG.debug(_("Connecting to {h!r}, port {p} as {u!r} per SSH ...").format(
+ h=self.tpl_ip, p=self.ssh_port, u=self.ssh_user))
+ ssh.connect(
+ self.tpl_ip, port=self.ssh_port, timeout=self.ssh_timeout,
+ username=self.ssh_user, key_filename=self.private_ssh_key)
+
+ if self.verbose > 1:
+ LOG.debug(_("Commands to execute:") + '\n' + cmd)
+
+ stdin, stdout, stderr = ssh.exec_command(
+ cmd, timeout=self.ssh_timeout)
+
+ result['out'] = to_str(stdout.read()).strip()
+ result['err'] = to_str(stderr.read()).strip()
+
+ LOG.debug(_("Output on {}:").format('STDERR') + '\n' + result['err'])
+
+ finally:
+ if ssh:
+ if self.verbose > 2:
+ LOG.debug(_("Closing SSH connection."))
+ ssh.close()
+
+ return result
+
+ # -------------------------------------------------------------------------
+ def show_install_log(self):
+
+ LOG.info(_("Showing post install log ..."))
+ install_logfile = '/var/log/anaconda/post-install.log'
+
+ cmd = textwrap.dedent("""\
+ if [ -f {log} ] ; then
+ echo "-----------------------------------------------------------"
+ cat {log}
+ echo "-----------------------------------------------------------"
+ echo
+ else
+ echo "Post install log {log} not found!" >&2
+ fi
+
+ """).format(log=install_logfile)
+
+ result = self.exec_remote(cmd)
+
+ if result['err']:
+ LOG.error(result['err'])
+ if self.postinstall_errors:
+ self.postinstall_errors += result['err']
+ else:
+ self.postinstall_errors = result['err']
+ else:
+ LOG.debug("Post install log:\n\n" + result['out'])
+
+ # -------------------------------------------------------------------------
+ def get_postinstall_error(self):
+
+ LOG.info(_("Trying to get possible post-installation errors ..."))
+
+ cmd = textwrap.dedent("""\
+ if [ -f /root/postinst-error.txt ] ; then
+ cat /root/postinst-error.txt
+ fi
+ """)
+
+ result = self.exec_remote(cmd)
+ if result['out']:
+ if self.postinstall_errors:
+ self.postinstall_errors += result['out']
+ else:
+ self.postinstall_errors = result['out']
+ LOG.error(_("Got postinstall errors:") + '\n' + result['out'])
+ else:
+ LOG.info(_("No postinstall errors found."))
+
+ if self.postinstall_errors:
+ LOG.warn(_("Template VM {!r} has to be removed.").format(self.tpl_ip))
+
+ # -------------------------------------------------------------------------
+ def post_install_tasks_ssh(self):
+
+ LOG.info(_("Executing tasks per SSH after installation ..."))
+ print_section_start('post_install_tasks', 'Exec post install tasks ...', collapsed=True)
+
+ logfiles = (
+ '/var/log/boot.log',
+ '/var/log/cron',
+ '/var/log/dnf*.log',
+ '/var/log/hawkey.log',
+ '/var/log/messages',
+ '/var/log/secure',
+ '/var/log/wtmp',
+ '/var/log/vmware-*.log*',
+ '/var/log/yum*.log',
+ )
+
+ cmd = textwrap.dedent("""\
+ printf "Current host FQDN: "
+ hostname -f
+
+ for ks_cfg in "/root/original-ks.cfg" "/root/anaconda-ks.cfg" ; do
+ echo
+ echo "-----------------------------------------------------------"
+ if [ -f "${ks_cfg}" ] ; then
+ echo "Moving ${ks_cfg} => /var/log/anaconda/ ..."
+ mv -v "${ks_cfg}" /var/log/anaconda/
+ else
+ echo "File ${ks_cfg} not found." >&2
+ fi
+ done
+
+ for f in @@@LOGFILES@@@ ; do
+ if [ -f "${f}" ] ; then
+ echo "Truncating ${f} ..."
+ cp /dev/null "${f}"
+ fi
+ done
+
+ echo
+ echo "-----------------------------------------------------------"
+ echo "Current network configuration:"
+ echo
+ /usr/sbin/ip address show
+ echo
+ echo "Current routing configuration:"
+ echo
+ /usr/sbin/ip route show
+ echo
+
+ """).replace('@@@LOGFILES@@@', ' '.join(logfiles))
+
+ result = self.exec_remote(cmd)
+ LOG.debug(_("Output on {}:").format('STDOUT') + '\n' + result['out'])
+ if not result['err']:
+ LOG.debug(_("No output on {}.").format('STDERR'))
+
+ print_section_end('post_install_tasks')
+
+ if result['err']:
+ LOG.warn(_("Output on {}:").format('STDERR') + '\n' + result['err'])
+
+ # -------------------------------------------------------------------------
+ def poweroff_vm(self):
+
+ wait_for_shutdown = 15
+
+ LOG.info(_("Waiting for {} seconds before shutting down:").format(wait_for_shutdown))
+ print(' ==> ', end='', flush=True)
+
+ start_waiting = time.time()
+ cur_time = start_waiting
+ cur_duration = 0
+ last_dot = cur_time
+
+ i = 0
+ while cur_duration <= wait_for_shutdown:
+ time.sleep(0.1)
+ cur_time = time.time()
+ if (cur_time - last_dot) >= 1:
+ print('.', end='', flush=True)
+ last_dot = cur_time
+ i += 1
+ if not i % 60:
+ print('\n ', end='', flush=True)
+ cur_duration = cur_time - start_waiting
+ print('', flush=True)
+
+ LOG.info(_("Last actions before powering off VM {!r} ...").format(self.tpl_ip))
+
+ cmd = textwrap.dedent("""\
+ echo
+ echo "-----------------------------------------------------------"
+ echo "Cleaning up /root/.ssh/authorized_keys ..."
+ afile="/root/.ssh/authorized_keys"
+ tfile="/tmp/authorized_keys"
+ pattern="create-vmware-tpl@pixelpark.com"
+
+ cat "${afile}" | grep -v "${pattern}" > "${tfile}"
+ mv -v "${tfile}" "${afile}"
+
+ echo
+ echo "-----------------------------------------------------------"
+ echo "Removing SSH host keys ..."
+ rm -v /etc/ssh/ssh_host_*
+
+ echo
+ echo "Sleeping some seconds ..."
+ sleep 3
+
+ echo
+ echo "-----------------------------------------------------------"
+ echo "Powering off ..."
+ poweroff && logout
+
+ """)
+
+ vm = self.get_temp_tpl_vm()
+ power_state = vm.runtime.powerState
+ LOG.debug(_("Current state of template VM is {!r}").format(power_state))
+ if power_state.strip().lower() == "poweredoff":
+ LOG.info(_("Template VM is already shut off."))
+ return
+
+ if power_state.strip().lower() != "poweredon":
+ raise ExpectedHandlerError(
+ _("Cannot shut down VM {h!r}, is currently in state {s!r}.").format(
+ h=self.tpl_ip, s=power_state))
+
+ LOG.info(_("Powering off VM {!r} per SSH ...").format(self.tpl_ip))
+ print_section_start('poweroff', 'Powering off VM ...', collapsed=True)
+ result = self.exec_remote(cmd)
+
+ LOG.debug(_("Output on {}:").format('STDOUT') + '\n' + result['out'])
+ if not result['err']:
+ LOG.debug(_("No output on {}.").format('STDERR'))
+
+ print_section_end('poweroff')
+
+ if result['err']:
+ LOG.warn(_("Output on {}:").format('STDERR') + '\n' + result['err'])
+
+ cur_diff = 0
+ start_shutdown = time.time()
+ cur_time = start_shutdown
+ last_dot = cur_time
+ i = 0
+
+ LOG.debug(_("Waiting for successful shut down of VM ..."))
+ if self.verbose <= 3:
+ print(' ==> ', end='', flush=True)
+ if self.verbose > 3:
+ LOG.debug(_("Current state of template VM is {!r}").format(power_state))
+
+ while power_state.strip().lower() != "poweredoff":
+
+ time.sleep(0.2)
+
+ dot = '.'
+ if power_state.lower().strip() != 'poweredon':
+ dot = 'S'
+
+ cur_time = time.time()
+ cur_diff = cur_time - start_shutdown
+ if (self.verbose <= 3) and ((cur_time - last_dot) >= self.interval_dot):
+ print(dot, end='', flush=True)
+ i += 1
+ if i >= 60:
+ print('', flush=True)
+ print(' ', end='', flush=True)
+ i = 0
+ last_dot = cur_time
+
+ vm = self.get_temp_tpl_vm()
+ power_state = vm.runtime.powerState
+ if self.verbose > 3:
+ LOG.debug(_(
+ "Still waiting for completing shutdown, current state is {!r}.").format(
+ power_state))
+ if power_state.strip().lower() == "poweredoff":
+ print('', flush=True)
+ LOG.info(_(
+ "Template VM {h!r} was shutting down in {t:0.1f} seconds.").format(
+ h=self.tpl_ip, t=cur_diff))
+ return
+ if cur_diff >= self.cfg.max_wait_for_shutdown_vm:
+ break
+
+ print('', flush=True)
+ raise ExpectedHandlerError(_(
+ "VM {h!r} was not shut down after {t:0.1f} seconds, current state is {s!r}.").format(
+ h=self.tpl_ip, t=cur_diff, s=power_state))
# =============================================================================