path: root/scripts/check-qemu-install

#!/usr/bin/env python3
#
# Copyright (C) 2019, VyOS maintainers and contributors
#
# This program is free software; you can redistribute it and/or modify
# it under the terms of the GNU General Public License version 2 or later as
# published by the Free Software Foundation.
#
# This program is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
# GNU General Public License for more details.
#
# You should have received a copy of the GNU General Public License
# along with this program.  If not, see <http://www.gnu.org/licenses/>.
#
# File: check-qemu-install
# Purpose:
#  This script installs a system on a emulated qemu host to verify
#  that the iso produced is installable and boots.
#  after the iso is booted from disk it also tries to execute the
#  vyos-smoketest script to verify checks there.
#
#  For now it will not fail on failed smoketest but will fail on
#  install and boot errors.
#  Arguments:
#    iso            iso image to install
#    [disk]         disk filename to use, if none is provided it
#                   is autogenerated
#    [--keep]       Keep the disk image after completion
#    [--logfile]    name of logfile to save, defaulting to stdout
#    [--silent]     only print on errors
#    [--debug]      print all communication with the device

import pexpect
import sys
import os
import time
import argparse
import subprocess
import random
import traceback
import logging
import re
from io import BytesIO, StringIO
from datetime import datetime

EXCEPTION = 0
now = datetime.now()

parser = argparse.ArgumentParser(description='Install and start a test VyOS vm.')
parser.add_argument('iso', help='ISO file to install')
parser.add_argument('disk', help='name of disk image file',
                            nargs='?',
                            default='testinstall-{}-{}.img'.format(now.strftime('%Y%m%d-%H%M%S'),
                                                                   "%04x" % random.randint(0,65535)))
parser.add_argument('--keep', help='Do not remove disk-image after installation',
                              action='store_true',
                              default=False)
parser.add_argument('--silent', help='Do not show output on stdout unless an error has occured',
                              action='store_true',
                              default=False)
parser.add_argument('--debug', help='Send all debug output to stdout',
                               action='store_true',
                               default=False)
parser.add_argument('--logfile', help='Log to file')
parser.add_argument('--no-kvm', help='Disable use of kvm',
				action='store_true',
				default=False)

args = parser.parse_args()

class StreamToLogger(object):
    """
    Fake file-like stream object that redirects writes to a logger instance.
    """
    def __init__(self, logger, log_level=logging.INFO):
        self.logger = logger
        self.log_level = log_level
        self.linebuf = b''
        self.ansi_escape = re.compile(r'\x1B[@-_][0-?]*[ -/]*[@-~]')

    def write(self, buf):
        self.linebuf += buf
        #print('.')
        while b'\n' in self.linebuf:
            f = self.linebuf.split(b'\n', 1)
            if len(f) == 2:
                self.logger.debug(self.ansi_escape.sub('', f[0].decode(errors="replace").rstrip()))
                self.linebuf = f[1]
            #print(f)


    def flush(self):
        pass

def get_qemu_cmd(name, enable_kvm, disk_img, iso_img=None):
    kvm = ""
    cpu = "-cpu host"
    if not enable_kvm:
        kvm = "--no-kvm"
        cpu = ""

    cdrom = ""
    if iso_img:
        cdrom = "-boot d -cdrom {}".format(iso_img)

    cmd = 'qemu-system-x86_64 \
        -name "{NAME}" \
        -m 1G \
        -nic user,model=virtio,mac=52:54:99:12:34:56 \
        -nic user,model=virtio,mac=52:54:99:12:34:57 \
        -nic user,model=virtio,mac=52:54:99:12:34:58 \
        -nic user,model=virtio,mac=52:54:99:12:34:59 \
        -machine accel=kvm \
        {CPU} \
        -smp 2 \
        -nographic \
        {CD} \
        {KVM} \
        -drive format=raw,file={DISK}'.format(NAME=name, CD=cdrom, DISK=disk_img, KVM=kvm, CPU=cpu)

    return cmd


# Setting up logger
log = logging.getLogger()
log.setLevel(logging.DEBUG)

stl = StreamToLogger(log)
formatter = logging.Formatter('%(levelname)5s - %(message)s')

handler = logging.StreamHandler(sys.stdout)
if args.silent:
    handler.setLevel(logging.ERROR)
elif args.debug:
    handler.setLevel(logging.DEBUG)
else:
    handler.setLevel(logging.INFO)

handler.setFormatter(formatter)
log.addHandler(handler)

if args.logfile:
    filehandler = logging.FileHandler(args.logfile)
    filehandler.setLevel(logging.DEBUG)
    filehandler.setFormatter(formatter)
    log.addHandler(filehandler)

if args.silent:
    output = BytesIO()
else:
    output = sys.stdout.buffer

if not os.path.isfile(args.iso):
    log.error("Unable to find iso image to install")
    sys.exit(1)

if args.no_kvm:
    log.error("KVM forced off by command line")
    kvm=False
elif not os.path.exists("/dev/kvm"):
    log.error("KVM is not enabled on host, proceeding with software emulation")
    kvm=False
else:
    kvm=True

# Creating diskimage!!
if not os.path.isfile(args.disk):
    log.info("Creating Disk image {}".format(args.disk))
    c = subprocess.check_output(["qemu-img", "create", args.disk, "2G"])
    log.debug(c.decode())
else:
    log.info("Diskimage already exists, using the existing one")

try:
    #################################################
    # Installing image to disk
    #################################################
    log.info("Installing system")
    cmd = get_qemu_cmd("TESTVM", kvm, args.disk, args.iso)
    log.debug("Executing command: {}".format(cmd))
    c = pexpect.spawn(cmd, logfile=stl)

    #################################################
    # Logging into VyOS system
    #################################################
    try:
        c.expect('Automatic boot in', timeout=10)
        c.sendline('')
    except pexpect.TIMEOUT:
        log.warning("Did not find grub countdown window, ignoring")

    log.info('Waiting for login prompt')
    c.expect('[Ll]ogin:', timeout=300)
    c.sendline('vyos')
    c.expect('[Pp]assword:', timeout=10)
    c.sendline('vyos')
    c.expect(r'vyos@vyos:~\$')
    log.info('Logged in!')

    #################################################
    # Installing into VyOS system
    #################################################
    log.info("Starting installer")
    c.sendline('install image')
    c.expect('\nWould you like to continue?.*:')
    c.sendline('yes')
    log.info("Partitioning disk")
    c.expect('\nPartition.*:')
    c.sendline('')
    c.expect('\nInstall the image on.*:')
    c.sendline('')
    c.expect(r'\nContinue\?.*:')
    c.sendline('Yes')
    c.expect('\nHow big of a root partition should I create?.*:')
    c.sendline('')
    log.info('Disk partitioned, installing')
    c.expect('\nWhat would you like to name this image?.*:')
    c.sendline('')
    log.info('Copying files')
    c.expect('\nWhich one should I copy to.*:', timeout=300)
    c.sendline('')
    log.info('Files Copied!')
    c.expect('\nEnter password for user.*:')
    c.sendline('vyos')
    c.expect('\nRetype password for user.*:')
    c.sendline('vyos')
    c.expect('\nWhich drive should GRUB modify the boot partition on.*:')
    c.sendline('')
    c.expect(r'\nvyos@vyos:~\$')
    log.info('system installed, shutting down')

    #################################################
    # Powering down installer
    #################################################
    log.info("Shutting down installation system")
    c.sendline('poweroff')
    c.expect(r'\nAre you sure you want to poweroff this system.*\]')
    c.sendline('Y')
    for i in range(30):
        log.info("Waiting for shutdown...")
        if not c.isalive():
            log.info("VM is shut down!")
            break
        time.sleep(10)
    else:
        log.error("VM Did not shut down after 300sec, killing")
    c.close()

    #################################################
    # Booting installed system
    #################################################
    log.info("Booting installed system")
    cmd = get_qemu_cmd("TESTVM", kvm, args.disk)
    log.debug('Executing command: {}'.format(cmd))
    c = pexpect.spawn(cmd, logfile=stl)

    #################################################
    # Logging into VyOS system
    #################################################
    try:
        c.expect('The highlighted entry will be executed automatically in', timeout=10)
        c.sendline('')
    except pexpect.TIMEOUT:
        log.warning("Did not find grub countdown window, ignoring")

    log.info('Waiting for login prompt')
    c.expect('[Ll]ogin:', timeout=300)
    c.sendline('vyos')
    c.expect('[Pp]assword:', timeout=10)
    c.sendline('vyos')
    c.expect(r'vyos@vyos:~\$')
    log.info('Logged in!')

    # additional settling time
    time.sleep(20)

    #################################################
    # Basic Configmode/Opmode switch
    #################################################
    log.info("Basic CLI configuration mode test")
    c.sendline('configure')
    c.expect(r'vyos@vyos#')
    c.sendline('run show version')
    c.sendline('exit')
    c.expect(r'vyos@vyos:~\$')

    #################################################
    # Executing test-suite
    #################################################
    log.info("Executing test-suite ")

    c.sendline('sudo /usr/bin/vyos-smoketest')
    i = c.expect(['\n +Invalid command:',
                      '\n +Set failed',
                      'No such file or directory',
                      r'\n\S+@\S+[$#]'], timeout=1800)

    if i==0:
        raise Exception('Invalid command detected')
    elif i==1:
        raise Exception('Set syntax failed :/')
    elif i==2:
        log.error("Did not find VyOS smoketest, this should be an exception")
        raise Exception("WTF? did not find VyOS smoketest, this should be an exception")

    c.sendline('echo EXITCODE:$\x16?')
    i = c.expect(['EXITCODE:0', 'EXITCODE:\d+'], timeout=10)
    if i==0:
        log.info('Smoketest finished successfully!')
        pass
    if i==1:
        log.error('Smoketest failed :/')
        raise Exception("Smoketest-failed, please look into debug output")

    #log.info("Smoke test status")
    #data = c.before.decode()

    #################################################
    # Powering off system
    #################################################
    log.info("Powering off system ")
    c.sendline('poweroff')
    c.expect(r'\nAre you sure you want to poweroff this system.*\]')
    c.sendline('Y')
    log.info("Shutting down virtual machine")
    for i in range(30):
        log.info("Waiting for shutdown...")
        if not c.isalive():
            log.info("VM is shut down!")
            break
        time.sleep(10)
    else:
        log.error("VM Did not shut down after 300sec")
        raise Exception("VM Did not shut down after 300sec")
    c.close()

except pexpect.exceptions.TIMEOUT:
    log.error("Timeout waiting for VyOS system")
    log.error(traceback.format_exc())
    EXCEPTION = 1

except pexpect.exceptions.ExceptionPexpect:
    log.error("Exeption while executing QEMU")
    log.error("Is qemu working on this system?")
    log.error(traceback.format_exc())
    EXCEPTION = 1

except Exception:
    log.error("An unknown error occured when installing the VyOS system")
    traceback.print_exc()
    EXCEPTION = 1

#################################################
# Cleaning up
#################################################
log.info("Cleaning up")

if not args.keep:
    log.info("Removing disk file: {}".format(args.disk))
    try:
        os.remove(args.disk)
    except Exception:
        log.error("Exception while removing diskimage")
        log.error(traceback.format_exc())
        EXCEPTION = 1

if EXCEPTION:
    log.error("Hmm... System got an exception while processing")
    log.error("The ISO is not considered usable")
    sys.exit(1)