Update the Virtualization Test to Clean up Logs (Bugfix)

providers/base/bin/virtualization.py

@@ -734,22 +734,26 @@ def __init__(self, template=None, image=None):
         self.default_remote = "ubuntu:"
         self.os_version = get_release_to_test()
 
-    def run_command(self, cmd):
+    def run_command(self, cmd, log_stderr=True):
         task = RunCommand(cmd)
         if task.returncode != 0:
-            logging.error('Command {} returned a code of {}'.format(
-                task.cmd, task.returncode))
-            logging.error(' STDOUT: {}'.format(task.stdout))
-            logging.error(' STDERR: {}'.format(task.stderr))
+            logging.error(
+                "Command {} returned a code of {}".format(
+                    task.cmd, task.returncode
+                )
+            )
+            logging.error(" STDOUT: {}".format(task.stdout))
+            if log_stderr:
+                logging.error(" STDERR: {}".format(task.stderr))
             return False
         else:
-            logging.debug('Command {}:'.format(task.cmd))
-            if task.stdout != '':
-                logging.debug(' STDOUT: {}'.format(task.stdout))
-            elif task.stderr != '':
-                logging.debug(' STDERR: {}'.format(task.stderr))
-            else:
-                logging.debug(' Command returned no output')
+            logging.debug("Command {}:".format(task.cmd))
+            if task.stdout != "":
+                logging.debug(" STDOUT: {}".format(task.stdout))
+            if task.stderr and log_stderr:
+                logging.debug(" STDERR: {}".format(task.stderr))
+            if not (task.stderr or task.stdout):
+                logging.debug(" Command returned no output")
             return True
 
     def setup(self):
@@ -842,59 +846,57 @@ def cleanup(self):
         Clean up test files an Virtual Machines created
         """
         logging.debug('Cleaning up images and VMs created during test')
-        self.run_command('lxc image delete {}'.format(self.image_alias))
-        self.run_command('lxc delete --force {}'.format(self.name))
+        self.run_command('lxc image delete {}'.format(self.image_alias), False)
+        self.run_command('lxc delete --force {}'.format(self.name), False)
 
     def start_vm(self):
         """
         Creates an lxd virtual machine and performs the test
         """
-        wait_interval = 5
-        test_interval = 300
 
-        result = self.setup()
-        if not result:
+        if not self.setup():
             logging.error("One or more setup stages failed.")
             return False
 
         # Create Virtual Machine
         logging.debug("Launching Virtual Machine")
         if not self.image_url and not self.template_url:
-            logging.debug("No local image available, attempting to "
-                          "import from default remote.")
-            cmd = ('lxc init {}{} {} --vm '.format(
-               self.default_remote, self.os_version, self.name))
+            logging.debug(
+                "No local image available, attempting to "
+                "import from default remote."
+            )
+            cmd = "lxc init {}{} {} --vm ".format(
+                self.default_remote, self.os_version, self.name
+            )
         else:
-            cmd = ('lxc init {} {} --vm'.format(self.image_alias, self.name))
+            cmd = "lxc init {} {} --vm".format(self.image_alias, self.name)
 
         if not self.run_command(cmd):
             return False
 
         logging.debug("Start VM:")
-        cmd = ("lxc start {} ".format(self.name))
-        if not self.run_command(cmd):
+        if not self.run_command("lxc start {} ".format(self.name)):
             return False
 
         logging.debug("Virtual Machine listing:")
-        cmd = ("lxc list")
-        if not self.run_command(cmd):
+        if not self.run_command("lxc list"):
             return False
 
         logging.debug("Wait for vm to boot")
-        check_vm = 0
-        while check_vm < test_interval:
+        wait_interval = 5
+        max_wait_duration = 300
+        time_waited = 0
+        while time_waited < max_wait_duration:
             time.sleep(wait_interval)
-            cmd = ("lxc exec {} -- lsb_release -a".format(self.name))
-            if self.run_command(cmd):
+            cmd = "lxc exec {} -- lsb_release -a".format(self.name)
+            if self.run_command(cmd, False):
                 print("Vm started and booted successfully")
                 return True
-            else:
-                logging.debug("Re-verify VM booted")
-                check_vm = check_vm + wait_interval
+            logging.debug("Re-verify VM booted")
+            time_waited += wait_interval
 
         logging.debug("testing vm failed")
-        if check_vm == test_interval:
-            return False
+        return False
 
 
 def test_lxd_vm(args):

providers/base/tests/test_virtualization.py

@@ -0,0 +1,220 @@
+#!/usr/bin/env python3
+# encoding: utf-8
+# Copyright 2024 Canonical Ltd.
+# Written by:
+#   Massimiliano Girardi <massimiliano.girardi@canonical.com>
+#
+# This program is free software: you can redistribute it and/or modify
+# it under the terms of the GNU General Public License version 3,
+# 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/>.
+
+import itertools
+from unittest import TestCase
+from unittest.mock import patch, MagicMock
+
+from virtualization import LXDTest_vm
+
+
+class TestLXDTest_vm(TestCase):
+    @patch("virtualization.logging")
+    @patch("virtualization.RunCommand")
+    def test_run_command_no_stderr(self, run_command_mock, logging_mock):
+        task = run_command_mock()
+        task.returncode = 0
+        task.stdout = "abc"
+        task.stderr = None
+
+        command_result = LXDTest_vm.run_command(
+            MagicMock(), "command", log_stderr=True
+        )
+
+        self.assertTrue(logging_mock.debug.called)
+        self.assertTrue(command_result)
+
+    @patch("virtualization.logging")
+    @patch("virtualization.RunCommand")
+    def test_run_command_no_log_stderr(self, run_command_mock, logging_mock):
+        task = run_command_mock()
+        task.returncode = 1
+        task.stdout = "abc"
+        task.stderr = None
+
+        command_result = LXDTest_vm.run_command(
+            MagicMock(), "command", log_stderr=False
+        )
+
+        self.assertFalse(command_result)
+
+    @patch("virtualization.logging")
+    @patch("virtualization.RunCommand")
+    def test_run_command_error(self, run_command_mock, logging_mock):
+        task = run_command_mock()
+        task.returncode = 1
+        task.stdout = "abc"
+        task.stderr = "some error"
+
+        command_result = LXDTest_vm.run_command(
+            MagicMock(), "command", log_stderr=True
+        )
+
+        self.assertTrue(logging_mock.error.called)
+        self.assertFalse(command_result)
+
+    @patch("virtualization.logging")
+    @patch("virtualization.RunCommand")
+    def test_run_command_ok(self, run_command_mock, logging_mock):
+        task = run_command_mock()
+        task.returncode = 0
+        task.stdout = "abc"
+        task.stderr = "some error"
+
+        command_result = LXDTest_vm.run_command(
+            MagicMock(), "command", log_stderr=True
+        )
+
+        self.assertTrue(logging_mock.debug.called)
+        self.assertTrue(command_result)
+
+    @patch("virtualization.logging")
+    @patch("virtualization.RunCommand")
+    def test_run_command_ok_no_stdout(self, run_command_mock, logging_mock):
+        task = run_command_mock()
+        task.returncode = 0
+        task.stdout = ""
+        task.stderr = "some error"
+
+        command_result = LXDTest_vm.run_command(
+            MagicMock(), "command", log_stderr=True
+        )
+
+        self.assertTrue(logging_mock.debug.called)
+        self.assertTrue(command_result)
+
+
+    @patch("virtualization.logging")
+    def test_cleanup(self, logging_mock):
+        self_mock = MagicMock()
+        LXDTest_vm.cleanup(self_mock)
+
+        self.assertTrue(self_mock.run_command.called)
+
+    @patch("virtualization.logging")
+    def test_start_vm_fail_setup(self, logging_mock):
+        self_mock = MagicMock()
+        self_mock.setup.return_value = False
+
+        start_result = LXDTest_vm.start_vm(self_mock)
+
+        self.assertTrue(self_mock.setup.called)
+        self.assertTrue(logging_mock.error.called)
+        self.assertFalse(start_result)
+
+    @patch("virtualization.logging")
+    def test_start_vm_fail_init_no_img_alias(self, logging_mock):
+        self_mock = MagicMock()
+        self_mock.setup.return_value = True
+        self_mock.image_url = None
+        self_mock.template_url = None
+        self_mock.default_remote = "def remote"
+        self_mock.os_version = "os version"
+        self_mock.name = "name"
+        self_mock.run_command.side_effect = [False]
+
+        start_result = LXDTest_vm.start_vm(self_mock)
+
+        self.assertTrue(self_mock.setup.called)
+        self.assertFalse(start_result)
+
+    @patch("virtualization.logging")
+    def test_start_vm_fail_init_img_alias(self, logging_mock):
+        self_mock = MagicMock()
+        self_mock.setup.return_value = True
+        self_mock.image_url = "image url"
+        self_mock.template_url = "template url"
+        self_mock.name = "vm name"
+        self_mock.run_command.side_effect = [False]
+
+        start_result = LXDTest_vm.start_vm(self_mock)
+
+        self.assertTrue(self_mock.setup.called)
+        self.assertFalse(start_result)
+
+    @patch("virtualization.logging")
+    def test_start_vm_fail_start(self, logging_mock):
+        self_mock = MagicMock()
+        self_mock.setup.return_value = True
+        self_mock.image_url = "image url"
+        self_mock.template_url = "template url"
+        self_mock.name = "vm name"
+        self_mock.run_command.side_effect = [True, False]
+
+        start_result = LXDTest_vm.start_vm(self_mock)
+
+        self.assertTrue(self_mock.setup.called)
+        self.assertFalse(start_result)
+
+    @patch("virtualization.logging")
+    def test_start_vm_fail_list(self, logging_mock):
+        self_mock = MagicMock()
+        self_mock.setup.return_value = True
+        self_mock.image_url = "image url"
+        self_mock.template_url = "template url"
+        self_mock.name = "vm name"
+        self_mock.run_command.side_effect = [True, True, False]
+
+        start_result = LXDTest_vm.start_vm(self_mock)
+
+        self.assertTrue(self_mock.setup.called)
+        self.assertFalse(start_result)
+
+    @patch("time.sleep")
+    @patch("virtualization.logging")
+    def test_start_vm_fail_exec(self, logging_mock, time_sleep_mock):
+        self_mock = MagicMock()
+        self_mock.setup.return_value = True
+        self_mock.image_url = "image url"
+        self_mock.template_url = "template url"
+        self_mock.name = "vm name"
+        self_mock.run_command.side_effect = itertools.chain(
+            [True, True, True], itertools.repeat(False)
+        )
+
+        start_result = LXDTest_vm.start_vm(self_mock)
+
+        self.assertTrue(self_mock.setup.called)
+        self.assertFalse(start_result)
+
+    @patch("time.sleep")
+    @patch("virtualization.print")
+    @patch("virtualization.logging")
+    def test_start_vm_success(self, logging_mock, print_mock, time_sleep_mock):
+        self_mock = MagicMock()
+        self_mock.setup.return_value = True
+        self_mock.image_url = "image url"
+        self_mock.template_url = "template url"
+        self_mock.name = "vm name"
+        self_mock.run_command.side_effect = [True, True, True, True]
+
+        start_result = LXDTest_vm.start_vm(self_mock)
+
+        self.assertTrue(self_mock.setup.called)
+        self.assertTrue(start_result)
+        self.assertTrue(print_mock.called)
+
+    def test_setup_failure(self):
+        self_mock = MagicMock()
+        self_mock.run_command.return_value = False
+        self_mock.template_url = None
+        self_mock.image_url = None
+
+        setup_return = LXDTest_vm.setup(self_mock)
+
+        self.assertFalse(setup_return)