From 32c5555ed568193b8e23d36795abc7149b8e55e7 Mon Sep 17 00:00:00 2001 From: Frank Brehm Date: Tue, 10 Oct 2023 12:10:56 +0200 Subject: [PATCH] Moving VM related methods from lib/cr_vmware_tpl/handler/__init__.py into lib/cr_vmware_tpl/handler/vm.py --- lib/cr_vmware_tpl/handler/__init__.py | 434 +------------------------ lib/cr_vmware_tpl/handler/vm.py | 438 +++++++++++++++++++++++++- 2 files changed, 436 insertions(+), 436 deletions(-) diff --git a/lib/cr_vmware_tpl/handler/__init__.py b/lib/cr_vmware_tpl/handler/__init__.py index ead8b1c..e8a8c23 100644 --- a/lib/cr_vmware_tpl/handler/__init__.py +++ b/lib/cr_vmware_tpl/handler/__init__.py @@ -11,11 +11,8 @@ from __future__ import absolute_import, print_function # Standard module import logging import re -import random import time import datetime -import socket -import textwrap import signal import tempfile import os @@ -24,12 +21,11 @@ from pathlib import Path # 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 @@ -51,7 +47,7 @@ from ..cobbler import Cobbler from ..xlate import XLATOR -__version__ = '2.4.6' +__version__ = '2.4.7' LOG = logging.getLogger(__name__) TZ = pytz.timezone('Europe/Berlin') @@ -359,430 +355,6 @@ class CrTplHandler( 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): diff --git a/lib/cr_vmware_tpl/handler/vm.py b/lib/cr_vmware_tpl/handler/vm.py index c322226..3ba38b3 100644 --- a/lib/cr_vmware_tpl/handler/vm.py +++ b/lib/cr_vmware_tpl/handler/vm.py @@ -10,17 +10,23 @@ from __future__ import absolute_import, print_function # 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__) @@ -33,7 +39,429 @@ class HandlerVmMixin(): 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)) # ============================================================================= -- 2.39.5