[PATCH 7/8] python/qemu: allow avocado to set logging name space

["Alex Bennée" <alex.bennee@linaro.org>]

Since the update to the latest version Avocado only automatically
collects logging under the avocado name space. Tweak the QEMUMachine
class to allow avocado to bring logging under its name space. This
also allows useful tricks like:

  ./avocado --show avocado.qemu.machine run path/to/test

if you want to quickly get the machine invocation out of a test
without searching deeply through the logs.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
---
 python/qemu/machine/machine.py         | 42 ++++++++++++++------------
 tests/avocado/avocado_qemu/__init__.py |  3 +-
 2 files changed, 24 insertions(+), 21 deletions(-)

diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py
index e57c254484..402b9a0df9 100644
--- a/python/qemu/machine/machine.py
+++ b/python/qemu/machine/machine.py
@@ -49,10 +49,6 @@
 
 from . import console_socket
 
-
-LOG = logging.getLogger(__name__)
-
-
 class QEMUMachineError(Exception):
     """
     Exception called when an error in QEMUMachine happens.
@@ -131,6 +127,7 @@ def __init__(self,
                  drain_console: bool = False,
                  console_log: Optional[str] = None,
                  log_dir: Optional[str] = None,
+                 log_namespace: Optional[str] = None,
                  qmp_timer: Optional[float] = 30):
         '''
         Initialize a QEMUMachine
@@ -164,6 +161,11 @@ def __init__(self,
         self._sock_dir = sock_dir
         self._log_dir = log_dir
 
+        if log_namespace:
+            self.log = logging.getLogger(log_namespace)
+        else:
+            self.log = logging.getLogger(__name__)
+
         self._monitor_address = monitor_address
 
         self._console_log_path = console_log
@@ -382,11 +384,11 @@ def _post_shutdown(self) -> None:
         Called to cleanup the VM instance after the process has exited.
         May also be called after a failed launch.
         """
-        LOG.debug("Cleaning up after VM process")
+        self.log.debug("Cleaning up after VM process")
         try:
             self._close_qmp_connection()
         except Exception as err:  # pylint: disable=broad-except
-            LOG.warning(
+            self.log.warning(
                 "Exception closing QMP connection: %s",
                 str(err) if str(err) else type(err).__name__
             )
@@ -414,7 +416,7 @@ def _post_shutdown(self) -> None:
                 command = ' '.join(self._qemu_full_args)
             else:
                 command = ''
-            LOG.warning(msg, -int(exitcode), command)
+            self.log.warning(msg, -int(exitcode), command)
 
         self._quit_issued = False
         self._user_killed = False
@@ -458,7 +460,7 @@ def _launch(self) -> None:
         Launch the VM and establish a QMP connection
         """
         self._pre_launch()
-        LOG.debug('VM launch command: %r', ' '.join(self._qemu_full_args))
+        self.log.debug('VM launch command: %r', ' '.join(self._qemu_full_args))
 
         # Cleaning up of this subprocess is guaranteed by _do_shutdown.
         # pylint: disable=consider-using-with
@@ -507,7 +509,7 @@ def _early_cleanup(self) -> None:
         # for QEMU to exit, while QEMU is waiting for the socket to
         # become writable.
         if self._console_socket is not None:
-            LOG.debug("Closing console socket")
+            self.log.debug("Closing console socket")
             self._console_socket.close()
             self._console_socket = None
 
@@ -518,7 +520,7 @@ def _hard_shutdown(self) -> None:
         :raise subprocess.Timeout: When timeout is exceeds 60 seconds
             waiting for the QEMU process to terminate.
         """
-        LOG.debug("Performing hard shutdown")
+        self.log.debug("Performing hard shutdown")
         self._early_cleanup()
         self._subp.kill()
         self._subp.wait(timeout=60)
@@ -535,17 +537,17 @@ def _soft_shutdown(self, timeout: Optional[int]) -> None:
         :raise subprocess.TimeoutExpired: When timeout is exceeded waiting for
             the QEMU process to terminate.
         """
-        LOG.debug("Attempting graceful termination")
+        self.log.debug("Attempting graceful termination")
 
         self._early_cleanup()
 
         if self._quit_issued:
-            LOG.debug(
+            self.log.debug(
                 "Anticipating QEMU termination due to prior 'quit' command, "
                 "or explicit call to wait()"
             )
         else:
-            LOG.debug("Politely asking QEMU to terminate")
+            self.log.debug("Politely asking QEMU to terminate")
 
         if self._qmp_connection:
             try:
@@ -557,14 +559,14 @@ def _soft_shutdown(self, timeout: Optional[int]) -> None:
                 # Regardless, we want to quiesce the connection.
                 self._close_qmp_connection()
         elif not self._quit_issued:
-            LOG.debug(
+            self.log.debug(
                 "Not anticipating QEMU quit and no QMP connection present, "
                 "issuing SIGTERM"
             )
             self._subp.terminate()
 
         # May raise subprocess.TimeoutExpired
-        LOG.debug(
+        self.log.debug(
             "Waiting (timeout=%s) for QEMU process (pid=%s) to terminate",
             timeout, self._subp.pid
         )
@@ -586,9 +588,9 @@ def _do_shutdown(self, timeout: Optional[int]) -> None:
             self._soft_shutdown(timeout)
         except Exception as exc:
             if isinstance(exc, subprocess.TimeoutExpired):
-                LOG.debug("Timed out waiting for QEMU process to exit")
-            LOG.debug("Graceful shutdown failed", exc_info=True)
-            LOG.debug("Falling back to hard shutdown")
+                self.log.debug("Timed out waiting for QEMU process to exit")
+            self.log.debug("Graceful shutdown failed", exc_info=True)
+            self.log.debug("Falling back to hard shutdown")
             self._hard_shutdown()
             raise AbnormalShutdown("Could not perform graceful shutdown") \
                 from exc
@@ -611,9 +613,9 @@ def shutdown(self,
         if not self._launched:
             return
 
-        LOG.debug("Shutting down VM appliance; timeout=%s", timeout)
+        self.log.debug("Shutting down VM appliance; timeout=%s", timeout)
         if hard:
-            LOG.debug("Caller requests immediate termination of QEMU process.")
+            self.log.debug("Caller requests immediate termination of QEMU process.")
 
         try:
             if hard:
diff --git a/tests/avocado/avocado_qemu/__init__.py b/tests/avocado/avocado_qemu/__init__.py
index b19f797b7b..d925573299 100644
--- a/tests/avocado/avocado_qemu/__init__.py
+++ b/tests/avocado/avocado_qemu/__init__.py
@@ -322,7 +322,8 @@ def require_multiprocess(self):
     def _new_vm(self, name, *args):
         self._sd = tempfile.TemporaryDirectory(prefix="qemu_")
         vm = QEMUMachine(self.qemu_bin, base_temp_dir=self.workdir,
-                         sock_dir=self._sd.name, log_dir=self.logdir)
+                         sock_dir=self._sd.name, log_dir=self.logdir,
+                         log_namespace="avocado.qemu.machine")
         self.log.debug('QEMUMachine "%s" created', name)
         self.log.debug('QEMUMachine "%s" temp_dir: %s', name, vm.temp_dir)
         self.log.debug('QEMUMachine "%s" log_dir: %s', name, vm.log_dir)
-- 
2.39.2