All of lore.kernel.org
 help / color / mirror / Atom feed
* [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups
@ 2017-08-18 17:05 Amador Pahim
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 01/11] qemu.py: fix is_running() return before first launch() Amador Pahim
                   ` (11 more replies)
  0 siblings, 12 replies; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

Changes v1->v2:
 - Style fixes to make checkpatch.pl happy.
 - Rebased.
Changes v2->v3:
 - Fix typo in patch 3 ("qemu.py: make 'args' public") commit message.
Changes v3->v4:
 - Squash the 2 first commits since they are co-dependant.
 - Cleanup launch() and shutdown().
 - Reorder the commits, putting the rename of self._args first.
 - Rebased.
Changes v4->v5:
 - Break the cleanup commit into logical changes and include in the
   commit messages the rationale for making them.
Changes v5->v6:
 - Remove the commit to rename self._args.
 - Fix is_running() return before first call to maunch().
 - Use python logging system.
 - Include the full command line on negative exit code error message.
 - Use os.path.null instead of /dev/null.
 - Improve the control over the created/deleted files. 
Changes v6->v7:
 - Split commits in self-contained/atomic changes.
 - Addressed the comments from previous version, basically improving the
   logging messages and the control over created files. See individual
   commit messages for details.

Amador Pahim (11):
  qemu.py: fix is_running() return before first launch()
  qemu.py: avoid writing to stdout/stderr
  qemu.py: use os.path.null instead of /dev/null
  qemu.py: use poll() instead of 'returncode'
  qemu.py: cleanup redundant calls in launch()
  qemu.py: improve message on negative exit code
  qemu.py: include debug information on launch error
  qemu.py: make sure we only remove files we create
  qemu.py: launch vm only if it's not running
  qemu.py: don't launch again before shutdown()
  qemu.py: refactor launch()

 scripts/qemu.py | 141 ++++++++++++++++++++++++++++++++++++++++++--------------
 1 file changed, 106 insertions(+), 35 deletions(-)

-- 
2.13.5

^ permalink raw reply	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 01/11] qemu.py: fix is_running() return before first launch()
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 02/11] qemu.py: avoid writing to stdout/stderr Amador Pahim
                   ` (10 subsequent siblings)
  11 siblings, 0 replies; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

is_running() returns None when called before the first time we
call launch():

    >>> import qemu
    >>> vm = qemu.QEMUMachine('qemu-system-x86_64')
    >>> vm.is_running()
    >>>

It should return False instead. This patch fixes that.

For consistence, this patch removes the parenthesis from the
second clause as it's not really needed.

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 880e3e8219..0ae5d39414 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -86,7 +86,7 @@ class QEMUMachine(object):
             raise
 
     def is_running(self):
-        return self._popen and (self._popen.returncode is None)
+        return self._popen is not None and self._popen.returncode is None
 
     def exitcode(self):
         if self._popen is None:
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 02/11] qemu.py: avoid writing to stdout/stderr
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 01/11] qemu.py: fix is_running() return before first launch() Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-22 10:24   ` Fam Zheng
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 03/11] qemu.py: use os.path.null instead of /dev/null Amador Pahim
                   ` (9 subsequent siblings)
  11 siblings, 1 reply; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

This module should not write directly to stdout/stderr. Instead, it
should either raise exceptions or just log the messages and let the
callers handle them and decide what to do. For example, scripts could
choose to send the log messages stderr or/and write them to a file if
verbose or debugging mode is enabled.

This patch replaces the writes to stderr by an exception in the
send_fd_scm() when _socket_scm_helper is not set or not present. In the
same method, the subprocess Popen will now redirect the stdout/stderr to
logging.debug instead of writing to system stderr. As consequence, since
the Popen.communicate() is now used (in order to get the stdout), the
further call to wait() became redundant and was replaced by
Popen.returncode.

The shutdown() message on negative exit code will now be logged
to logging.debug instead of written to system stderr.

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 29 +++++++++++++++++++++--------
 1 file changed, 21 insertions(+), 8 deletions(-)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 0ae5d39414..ef531bb23b 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -13,6 +13,7 @@
 #
 
 import errno
+import logging
 import string
 import os
 import sys
@@ -20,6 +21,15 @@ import subprocess
 import qmp.qmp
 
 
+LOG = logging.getLogger(__name__)
+
+
+class QEMUMachineError(Exception):
+    """
+    Exception called when an error in QEMUMachine happens.
+    """
+
+
 class QEMUMachine(object):
     '''A QEMU VM'''
 
@@ -62,18 +72,20 @@ class QEMUMachine(object):
         # In iotest.py, the qmp should always use unix socket.
         assert self._qmp.is_scm_available()
         if self._socket_scm_helper is None:
-            print >>sys.stderr, "No path to socket_scm_helper set"
-            return -1
+            raise QEMUMachineError("No path to socket_scm_helper set")
         if os.path.exists(self._socket_scm_helper) == False:
-            print >>sys.stderr, "%s does not exist" % self._socket_scm_helper
-            return -1
+            raise QEMUMachineError("%s does not exist" % self._socket_scm_helper)
         fd_param = ["%s" % self._socket_scm_helper,
                     "%d" % self._qmp.get_sock_fd(),
                     "%s" % fd_file_path]
         devnull = open('/dev/null', 'rb')
-        p = subprocess.Popen(fd_param, stdin=devnull, stdout=sys.stdout,
-                             stderr=sys.stderr)
-        return p.wait()
+        p = subprocess.Popen(fd_param, stdin=devnull, stdout=subprocess.PIPE,
+                             stderr=subprocess.STDOUT)
+        output = p.communicate()[0]
+        if output:
+            LOG.debug(output)
+
+        return p.returncode
 
     @staticmethod
     def _remove_if_exists(path):
@@ -154,7 +166,8 @@ class QEMUMachine(object):
 
             exitcode = self._popen.wait()
             if exitcode < 0:
-                sys.stderr.write('qemu received signal %i: %s\n' % (-exitcode, ' '.join(self._args)))
+                LOG.debug('qemu received signal %i: %s', -exitcode,
+                          ' '.join(self._args))
             self._load_io_log()
             self._post_shutdown()
 
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 03/11] qemu.py: use os.path.null instead of /dev/null
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 01/11] qemu.py: fix is_running() return before first launch() Amador Pahim
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 02/11] qemu.py: avoid writing to stdout/stderr Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-22 10:24   ` Fam Zheng
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 04/11] qemu.py: use poll() instead of 'returncode' Amador Pahim
                   ` (8 subsequent siblings)
  11 siblings, 1 reply; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

For increased portability, let's use os.path.devnull.

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index ef531bb23b..51545f7f97 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -78,7 +78,7 @@ class QEMUMachine(object):
         fd_param = ["%s" % self._socket_scm_helper,
                     "%d" % self._qmp.get_sock_fd(),
                     "%s" % fd_file_path]
-        devnull = open('/dev/null', 'rb')
+        devnull = open(os.path.devnull, 'rb')
         p = subprocess.Popen(fd_param, stdin=devnull, stdout=subprocess.PIPE,
                              stderr=subprocess.STDOUT)
         output = p.communicate()[0]
@@ -139,7 +139,7 @@ class QEMUMachine(object):
 
     def launch(self):
         '''Launch the VM and establish a QMP connection'''
-        devnull = open('/dev/null', 'rb')
+        devnull = open(os.path.devnull, 'rb')
         qemulog = open(self._qemu_log_path, 'wb')
         try:
             self._pre_launch()
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 04/11] qemu.py: use poll() instead of 'returncode'
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (2 preceding siblings ...)
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 03/11] qemu.py: use os.path.null instead of /dev/null Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-30 21:10   ` Eduardo Habkost
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 05/11] qemu.py: cleanup redundant calls in launch() Amador Pahim
                   ` (7 subsequent siblings)
  11 siblings, 1 reply; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

The 'returncode' Popen attribute is not guaranteed to be updated. It
actually depends on a call to either poll(), wait() or communicate().

On the other hand, poll() will: "Check if child process has terminated.
Set and return returncode attribute."

Let's use the poll() to check whether the process is running and also
to get the updated process exit code, when the process is finished.

As consequence, the shutdown() calls to self._load_io_log()
self._post_shutdown() are now always executed to make sure we cleanup
even if VM is not running when the shutdown() is called.

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 19 +++++++++++++------
 1 file changed, 13 insertions(+), 6 deletions(-)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 51545f7f97..774f971f69 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -98,12 +98,12 @@ class QEMUMachine(object):
             raise
 
     def is_running(self):
-        return self._popen is not None and self._popen.returncode is None
+        return self._popen is not None and self._popen.poll() is None
 
     def exitcode(self):
         if self._popen is None:
             return None
-        return self._popen.returncode
+        return self._popen.poll()
 
     def get_pid(self):
         if not self.is_running():
@@ -111,8 +111,15 @@ class QEMUMachine(object):
         return self._popen.pid
 
     def _load_io_log(self):
-        with open(self._qemu_log_path, "r") as fh:
-            self._iolog = fh.read()
+        '''
+        Load the Qemu log file content (if available) into the proper
+        instance variable
+        '''
+        try:
+            with open(self._qemu_log_path, "r") as fh:
+                self._iolog = fh.read()
+        except IOError:
+            pass
 
     def _base_args(self):
         if isinstance(self._monitor_address, tuple):
@@ -168,8 +175,8 @@ class QEMUMachine(object):
             if exitcode < 0:
                 LOG.debug('qemu received signal %i: %s', -exitcode,
                           ' '.join(self._args))
-            self._load_io_log()
-            self._post_shutdown()
+        self._load_io_log()
+        self._post_shutdown()
 
     underscore_to_dash = string.maketrans('_', '-')
     def qmp(self, cmd, conv_keys=True, **args):
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 05/11] qemu.py: cleanup redundant calls in launch()
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (3 preceding siblings ...)
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 04/11] qemu.py: use poll() instead of 'returncode' Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 06/11] qemu.py: improve message on negative exit code Amador Pahim
                   ` (6 subsequent siblings)
  11 siblings, 0 replies; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

Now that shutdown() is guaranteed to always execute self._load_io_log()
and self._post_shutdown(), their calls in 'except' became redundant and
we can safely replace it by a call to shutdown().

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 6 +-----
 1 file changed, 1 insertion(+), 5 deletions(-)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 774f971f69..902d4c6c78 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -155,11 +155,7 @@ class QEMUMachine(object):
                                            stderr=subprocess.STDOUT, shell=False)
             self._post_launch()
         except:
-            if self.is_running():
-                self._popen.kill()
-                self._popen.wait()
-            self._load_io_log()
-            self._post_shutdown()
+            self.shutdown()
             raise
 
     def shutdown(self):
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 06/11] qemu.py: improve message on negative exit code
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (4 preceding siblings ...)
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 05/11] qemu.py: cleanup redundant calls in launch() Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 07/11] qemu.py: include debug information on launch error Amador Pahim
                   ` (5 subsequent siblings)
  11 siblings, 0 replies; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

The current message shows 'self._args', which contains only part of the
options used in the Qemu command line.

This patch makes the qemu full args list an instance variable and then
uses it in the negative exit code message.

Message was moved outside the 'if is_running' block to make sure it will
be logged if the VM finishes before the call to shutdown().

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 26 +++++++++++++++++++-------
 1 file changed, 19 insertions(+), 7 deletions(-)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 902d4c6c78..0bcec4b3b1 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -49,6 +49,7 @@ class QEMUMachine(object):
         self._iolog = None
         self._socket_scm_helper = socket_scm_helper
         self._debug = debug
+        self._qemu_full_args = None
 
     # This can be used to add an unused monitor instance.
     def add_monitor_telnet(self, ip, port):
@@ -146,13 +147,18 @@ class QEMUMachine(object):
 
     def launch(self):
         '''Launch the VM and establish a QMP connection'''
+        self._qemu_full_args = None
         devnull = open(os.path.devnull, 'rb')
         qemulog = open(self._qemu_log_path, 'wb')
         try:
             self._pre_launch()
-            args = self._wrapper + [self._binary] + self._base_args() + self._args
-            self._popen = subprocess.Popen(args, stdin=devnull, stdout=qemulog,
-                                           stderr=subprocess.STDOUT, shell=False)
+            self._qemu_full_args = (self._wrapper + [self._binary] +
+                                    self._base_args() + self._args)
+            self._popen = subprocess.Popen(self._qemu_full_args,
+                                           stdin=devnull,
+                                           stdout=qemulog,
+                                           stderr=subprocess.STDOUT,
+                                           shell=False)
             self._post_launch()
         except:
             self.shutdown()
@@ -166,11 +172,17 @@ class QEMUMachine(object):
                 self._qmp.close()
             except:
                 self._popen.kill()
+            self._popen.wait()
+
+        exitcode = self.exitcode()
+        if exitcode is not None and exitcode < 0:
+            msg = 'qemu received signal -%i: %s'
+            if self._qemu_full_args:
+                command = ' '.join(self._qemu_full_args)
+            else:
+                command = ''
+            LOG.debug(msg, exitcode, command)
 
-            exitcode = self._popen.wait()
-            if exitcode < 0:
-                LOG.debug('qemu received signal %i: %s', -exitcode,
-                          ' '.join(self._args))
         self._load_io_log()
         self._post_shutdown()
 
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 07/11] qemu.py: include debug information on launch error
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (5 preceding siblings ...)
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 06/11] qemu.py: improve message on negative exit code Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-30 15:55   ` Cleber Rosa
  2017-08-31  9:47   ` Lukáš Doktor
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 08/11] qemu.py: make sure we only remove files we create Amador Pahim
                   ` (4 subsequent siblings)
  11 siblings, 2 replies; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

When launching a VM, if an exception happens and the VM is not
initiated, it might be useful to see the qemu command line and
the qemu command output.

This patch creates that message. Notice that self._iolog needs to be
cleaned up in the beginning of the launch() to make sure we will not
expose the qemu log from a previous launch if the current one fails.

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 0bcec4b3b1..29fd2469f9 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -147,6 +147,7 @@ class QEMUMachine(object):
 
     def launch(self):
         '''Launch the VM and establish a QMP connection'''
+        self._iolog = None
         self._qemu_full_args = None
         devnull = open(os.path.devnull, 'rb')
         qemulog = open(self._qemu_log_path, 'wb')
@@ -162,6 +163,13 @@ class QEMUMachine(object):
             self._post_launch()
         except:
             self.shutdown()
+
+            LOG.debug('Error launching VM')
+            if self._qemu_full_args:
+                LOG.debug('Command: %r', ' '.join(self._qemu_full_args))
+            if self._iolog:
+                LOG.debug('Output: %r', self._iolog)
+
             raise
 
     def shutdown(self):
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 08/11] qemu.py: make sure we only remove files we create
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (6 preceding siblings ...)
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 07/11] qemu.py: include debug information on launch error Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 09/11] qemu.py: launch vm only if it's not running Amador Pahim
                   ` (3 subsequent siblings)
  11 siblings, 0 replies; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

To launch a VM, we need to create basically two files: the monitor
socket (if it's a UNIX socket) and the qemu log file.

For the qemu log file, we currently just open the path, which will
create the file if it does not exist or overwrite the file if it does
exist.

For the monitor socket, if it already exists, we are currently removing
it, even if it's not created by us.

This patch moves to pre_launch() the responsibility to make sure we only
create files that are not pre-existent and to populate a list of
controlled files. This list will then be used as the reference of
files to remove during the cleanup (post_shutdown()).

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 33 ++++++++++++++++++++++++++-------
 1 file changed, 26 insertions(+), 7 deletions(-)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 29fd2469f9..9ae65e454e 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -41,6 +41,7 @@ class QEMUMachine(object):
             monitor_address = os.path.join(test_dir, name + "-monitor.sock")
         self._monitor_address = monitor_address
         self._qemu_log_path = os.path.join(test_dir, name + ".log")
+        self._qemu_log_fd = None
         self._popen = None
         self._binary = binary
         self._args = list(args) # Force copy args in case we modify them
@@ -50,6 +51,7 @@ class QEMUMachine(object):
         self._socket_scm_helper = socket_scm_helper
         self._debug = debug
         self._qemu_full_args = None
+        self._created_files = []
 
     # This can be used to add an unused monitor instance.
     def add_monitor_telnet(self, ip, port):
@@ -134,30 +136,47 @@ class QEMUMachine(object):
                 '-display', 'none', '-vga', 'none']
 
     def _pre_launch(self):
-        self._qmp = qmp.qmp.QEMUMonitorProtocol(self._monitor_address, server=True,
-                                                debug=self._debug)
+        try:
+            self._qmp = qmp.qmp.QEMUMonitorProtocol(self._monitor_address,
+                                                    server=True,
+                                                    debug=self._debug)
+        except:
+            raise
+        else:
+            if not isinstance(self._monitor_address, tuple):
+                self._created_files.append(self._monitor_address)
+
+        try:
+            flags = os.O_CREAT | os.O_EXCL | os.O_WRONLY
+            os.open(self._qemu_log_path, flags)
+        except:
+            raise
+        else:
+            self._created_files.append(self._qemu_log_path)
+            self._qemu_log_fd = open(self._qemu_log_path, 'wb')
 
     def _post_launch(self):
         self._qmp.accept()
 
     def _post_shutdown(self):
-        if not isinstance(self._monitor_address, tuple):
-            self._remove_if_exists(self._monitor_address)
-        self._remove_if_exists(self._qemu_log_path)
+        if self._qemu_log_fd is not None:
+            self._qemu_log_fd.close()
+
+        while self._created_files:
+            self._remove_if_exists(self._created_files.pop())
 
     def launch(self):
         '''Launch the VM and establish a QMP connection'''
         self._iolog = None
         self._qemu_full_args = None
         devnull = open(os.path.devnull, 'rb')
-        qemulog = open(self._qemu_log_path, 'wb')
         try:
             self._pre_launch()
             self._qemu_full_args = (self._wrapper + [self._binary] +
                                     self._base_args() + self._args)
             self._popen = subprocess.Popen(self._qemu_full_args,
                                            stdin=devnull,
-                                           stdout=qemulog,
+                                           stdout=self._qemu_log_fd,
                                            stderr=subprocess.STDOUT,
                                            shell=False)
             self._post_launch()
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 09/11] qemu.py: launch vm only if it's not running
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (7 preceding siblings ...)
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 08/11] qemu.py: make sure we only remove files we create Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-22 10:37   ` Fam Zheng
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 10/11] qemu.py: don't launch again before shutdown() Amador Pahim
                   ` (2 subsequent siblings)
  11 siblings, 1 reply; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

A new call to launch() with a running VM will fall in exception and
consequently call shutdown().

This patch makes launch() to raise an exception when it's called with VM
already running.

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 9ae65e454e..46e8ff3232 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -170,6 +170,9 @@ class QEMUMachine(object):
         self._iolog = None
         self._qemu_full_args = None
         devnull = open(os.path.devnull, 'rb')
+        if self.is_running():
+            raise QEMULaunchError('VM already running')
+
         try:
             self._pre_launch()
             self._qemu_full_args = (self._wrapper + [self._binary] +
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 10/11] qemu.py: don't launch again before shutdown()
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (8 preceding siblings ...)
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 09/11] qemu.py: launch vm only if it's not running Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 11/11] qemu.py: refactor launch() Amador Pahim
  2017-08-31 23:36 ` [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Eduardo Habkost
  11 siblings, 0 replies; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

If a VM is launched, files are created and a cleanup is required before
a new launch. This cleanup is executed by shutdown(), so shutdown() must
be called even if the VM is manually terminated (i.e. using kill).

This patch creates a control to make sure launch() will not be executed
again if shutdown() is not called after the previous launch().

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 46e8ff3232..2bd81afcf2 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -52,6 +52,7 @@ class QEMUMachine(object):
         self._debug = debug
         self._qemu_full_args = None
         self._created_files = []
+        self._pending_shutdown = False
 
     # This can be used to add an unused monitor instance.
     def add_monitor_telnet(self, ip, port):
@@ -173,6 +174,9 @@ class QEMUMachine(object):
         if self.is_running():
             raise QEMULaunchError('VM already running')
 
+        if self._pending_shutdown:
+            raise QEMULaunchError('Shutdown pending after previous launch')
+
         try:
             self._pre_launch()
             self._qemu_full_args = (self._wrapper + [self._binary] +
@@ -183,6 +187,7 @@ class QEMUMachine(object):
                                            stderr=subprocess.STDOUT,
                                            shell=False)
             self._post_launch()
+            self._pending_shutdown = True
         except:
             self.shutdown()
 
@@ -215,6 +220,7 @@ class QEMUMachine(object):
 
         self._load_io_log()
         self._post_shutdown()
+        self._pending_shutdown = False
 
     underscore_to_dash = string.maketrans('_', '-')
     def qmp(self, cmd, conv_keys=True, **args):
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [Qemu-devel] [PATCH v7 11/11] qemu.py: refactor launch()
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (9 preceding siblings ...)
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 10/11] qemu.py: don't launch again before shutdown() Amador Pahim
@ 2017-08-18 17:05 ` Amador Pahim
  2017-08-31 23:36 ` [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Eduardo Habkost
  11 siblings, 0 replies; 24+ messages in thread
From: Amador Pahim @ 2017-08-18 17:05 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

This is just an refactor to separate the exception handler from the
actual launch procedure, improving the readability and making future
maintenances in this piece of code easier.

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py | 33 ++++++++++++++++++++-------------
 1 file changed, 20 insertions(+), 13 deletions(-)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 2bd81afcf2..7f890ff8e5 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -167,10 +167,10 @@ class QEMUMachine(object):
             self._remove_if_exists(self._created_files.pop())
 
     def launch(self):
-        '''Launch the VM and establish a QMP connection'''
-        self._iolog = None
-        self._qemu_full_args = None
-        devnull = open(os.path.devnull, 'rb')
+        '''
+        Try to launch the VM and make sure we cleanup and expose the
+        command line/output in case of exception.
+        '''
         if self.is_running():
             raise QEMULaunchError('VM already running')
 
@@ -178,15 +178,7 @@ class QEMUMachine(object):
             raise QEMULaunchError('Shutdown pending after previous launch')
 
         try:
-            self._pre_launch()
-            self._qemu_full_args = (self._wrapper + [self._binary] +
-                                    self._base_args() + self._args)
-            self._popen = subprocess.Popen(self._qemu_full_args,
-                                           stdin=devnull,
-                                           stdout=self._qemu_log_fd,
-                                           stderr=subprocess.STDOUT,
-                                           shell=False)
-            self._post_launch()
+            self._launch()
             self._pending_shutdown = True
         except:
             self.shutdown()
@@ -199,6 +191,21 @@ class QEMUMachine(object):
 
             raise
 
+    def _launch(self):
+        '''Launch the VM and establish a QMP connection'''
+        self._iolog = None
+        self._qemu_full_args = None
+        devnull = open(os.path.devnull, 'rb')
+        self._pre_launch()
+        self._qemu_full_args = (self._wrapper + [self._binary] +
+                                self._base_args() + self._args)
+        self._popen = subprocess.Popen(self._qemu_full_args,
+                                       stdin=devnull,
+                                       stdout=self._qemu_log_fd,
+                                       stderr=subprocess.STDOUT,
+                                       shell=False)
+        self._post_launch()
+
     def shutdown(self):
         '''Terminate the VM and clean up'''
         if self.is_running():
-- 
2.13.5

^ permalink raw reply related	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 03/11] qemu.py: use os.path.null instead of /dev/null
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 03/11] qemu.py: use os.path.null instead of /dev/null Amador Pahim
@ 2017-08-22 10:24   ` Fam Zheng
  0 siblings, 0 replies; 24+ messages in thread
From: Fam Zheng @ 2017-08-22 10:24 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, stefanha, berrange, ehabkost, mreitz, kwolf, armbru,
	crosa, ldoktor

On Fri, 08/18 19:05, Amador Pahim wrote:
> For increased portability, let's use os.path.devnull.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index ef531bb23b..51545f7f97 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -78,7 +78,7 @@ class QEMUMachine(object):
>          fd_param = ["%s" % self._socket_scm_helper,
>                      "%d" % self._qmp.get_sock_fd(),
>                      "%s" % fd_file_path]
> -        devnull = open('/dev/null', 'rb')
> +        devnull = open(os.path.devnull, 'rb')
>          p = subprocess.Popen(fd_param, stdin=devnull, stdout=subprocess.PIPE,
>                               stderr=subprocess.STDOUT)
>          output = p.communicate()[0]
> @@ -139,7 +139,7 @@ class QEMUMachine(object):
>  
>      def launch(self):
>          '''Launch the VM and establish a QMP connection'''
> -        devnull = open('/dev/null', 'rb')
> +        devnull = open(os.path.devnull, 'rb')
>          qemulog = open(self._qemu_log_path, 'wb')
>          try:
>              self._pre_launch()
> -- 
> 2.13.5
> 

Reviewed-by: Fam Zheng <famz@redhat.com>

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 02/11] qemu.py: avoid writing to stdout/stderr
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 02/11] qemu.py: avoid writing to stdout/stderr Amador Pahim
@ 2017-08-22 10:24   ` Fam Zheng
  2017-08-22 11:11     ` Amador Pahim
  0 siblings, 1 reply; 24+ messages in thread
From: Fam Zheng @ 2017-08-22 10:24 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, stefanha, berrange, ehabkost, mreitz, kwolf, armbru,
	crosa, ldoktor

On Fri, 08/18 19:05, Amador Pahim wrote:
> This module should not write directly to stdout/stderr. Instead, it
> should either raise exceptions or just log the messages and let the
> callers handle them and decide what to do. For example, scripts could
> choose to send the log messages stderr or/and write them to a file if
> verbose or debugging mode is enabled.
> 
> This patch replaces the writes to stderr by an exception in the
> send_fd_scm() when _socket_scm_helper is not set or not present. In the
> same method, the subprocess Popen will now redirect the stdout/stderr to
> logging.debug instead of writing to system stderr. As consequence, since
> the Popen.communicate() is now used (in order to get the stdout), the
> further call to wait() became redundant and was replaced by
> Popen.returncode.
> 
> The shutdown() message on negative exit code will now be logged
> to logging.debug instead of written to system stderr.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 29 +++++++++++++++++++++--------
>  1 file changed, 21 insertions(+), 8 deletions(-)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index 0ae5d39414..ef531bb23b 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -13,6 +13,7 @@
>  #
>  
>  import errno
> +import logging
>  import string
>  import os
>  import sys
> @@ -20,6 +21,15 @@ import subprocess
>  import qmp.qmp
>  
>  
> +LOG = logging.getLogger(__name__)

Previously the messages written to sys.stderr always get printed, now it depends
on the log level and IIUC debug messages are not printed by default. Should
LOG.warn be used to replace sys.stderr instead of LOG.debug?

> +
> +
> +class QEMUMachineError(Exception):
> +    """
> +    Exception called when an error in QEMUMachine happens.
> +    """
> +
> +
>  class QEMUMachine(object):
>      '''A QEMU VM'''
>  
> @@ -62,18 +72,20 @@ class QEMUMachine(object):
>          # In iotest.py, the qmp should always use unix socket.
>          assert self._qmp.is_scm_available()
>          if self._socket_scm_helper is None:
> -            print >>sys.stderr, "No path to socket_scm_helper set"
> -            return -1
> +            raise QEMUMachineError("No path to socket_scm_helper set")
>          if os.path.exists(self._socket_scm_helper) == False:
> -            print >>sys.stderr, "%s does not exist" % self._socket_scm_helper
> -            return -1
> +            raise QEMUMachineError("%s does not exist" % self._socket_scm_helper)
>          fd_param = ["%s" % self._socket_scm_helper,
>                      "%d" % self._qmp.get_sock_fd(),
>                      "%s" % fd_file_path]
>          devnull = open('/dev/null', 'rb')
> -        p = subprocess.Popen(fd_param, stdin=devnull, stdout=sys.stdout,
> -                             stderr=sys.stderr)
> -        return p.wait()
> +        p = subprocess.Popen(fd_param, stdin=devnull, stdout=subprocess.PIPE,
> +                             stderr=subprocess.STDOUT)
> +        output = p.communicate()[0]
> +        if output:
> +            LOG.debug(output)
> +
> +        return p.returncode
>  
>      @staticmethod
>      def _remove_if_exists(path):
> @@ -154,7 +166,8 @@ class QEMUMachine(object):
>  
>              exitcode = self._popen.wait()
>              if exitcode < 0:
> -                sys.stderr.write('qemu received signal %i: %s\n' % (-exitcode, ' '.join(self._args)))
> +                LOG.debug('qemu received signal %i: %s', -exitcode,
> +                          ' '.join(self._args))
>              self._load_io_log()
>              self._post_shutdown()
>  
> -- 
> 2.13.5
> 

Fam

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 09/11] qemu.py: launch vm only if it's not running
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 09/11] qemu.py: launch vm only if it's not running Amador Pahim
@ 2017-08-22 10:37   ` Fam Zheng
  0 siblings, 0 replies; 24+ messages in thread
From: Fam Zheng @ 2017-08-22 10:37 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, stefanha, berrange, ehabkost, mreitz, kwolf, armbru,
	crosa, ldoktor

On Fri, 08/18 19:05, Amador Pahim wrote:
> A new call to launch() with a running VM will fall in exception and
> consequently call shutdown().
> 
> This patch makes launch() to raise an exception when it's called with VM
> already running.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 3 +++
>  1 file changed, 3 insertions(+)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index 9ae65e454e..46e8ff3232 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -170,6 +170,9 @@ class QEMUMachine(object):
>          self._iolog = None
>          self._qemu_full_args = None
>          devnull = open(os.path.devnull, 'rb')
> +        if self.is_running():
> +            raise QEMULaunchError('VM already running')
> +
>          try:
>              self._pre_launch()
>              self._qemu_full_args = (self._wrapper + [self._binary] +
> -- 
> 2.13.5
> 

Reviewed-by: Fam Zheng <famz@redhat.com>

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 02/11] qemu.py: avoid writing to stdout/stderr
  2017-08-22 10:24   ` Fam Zheng
@ 2017-08-22 11:11     ` Amador Pahim
  2017-08-22 11:56       ` Fam Zheng
  0 siblings, 1 reply; 24+ messages in thread
From: Amador Pahim @ 2017-08-22 11:11 UTC (permalink / raw)
  To: Fam Zheng
  Cc: qemu-devel, Stefan Hajnoczi, Daniel Berrange, Eduardo Habkost,
	Max Reitz, Kevin Wolf, Markus Armbruster, Cleber Rosa,
	Lukáš Doktor

On Tue, Aug 22, 2017 at 12:24 PM, Fam Zheng <famz@redhat.com> wrote:
> On Fri, 08/18 19:05, Amador Pahim wrote:
>> This module should not write directly to stdout/stderr. Instead, it
>> should either raise exceptions or just log the messages and let the
>> callers handle them and decide what to do. For example, scripts could
>> choose to send the log messages stderr or/and write them to a file if
>> verbose or debugging mode is enabled.
>>
>> This patch replaces the writes to stderr by an exception in the
>> send_fd_scm() when _socket_scm_helper is not set or not present. In the
>> same method, the subprocess Popen will now redirect the stdout/stderr to
>> logging.debug instead of writing to system stderr. As consequence, since
>> the Popen.communicate() is now used (in order to get the stdout), the
>> further call to wait() became redundant and was replaced by
>> Popen.returncode.
>>
>> The shutdown() message on negative exit code will now be logged
>> to logging.debug instead of written to system stderr.
>>
>> Signed-off-by: Amador Pahim <apahim@redhat.com>
>> ---
>>  scripts/qemu.py | 29 +++++++++++++++++++++--------
>>  1 file changed, 21 insertions(+), 8 deletions(-)
>>
>> diff --git a/scripts/qemu.py b/scripts/qemu.py
>> index 0ae5d39414..ef531bb23b 100644
>> --- a/scripts/qemu.py
>> +++ b/scripts/qemu.py
>> @@ -13,6 +13,7 @@
>>  #
>>
>>  import errno
>> +import logging
>>  import string
>>  import os
>>  import sys
>> @@ -20,6 +21,15 @@ import subprocess
>>  import qmp.qmp
>>
>>
>> +LOG = logging.getLogger(__name__)
>
> Previously the messages written to sys.stderr always get printed, now it depends
> on the log level and IIUC debug messages are not printed by default. Should
> LOG.warn be used to replace sys.stderr instead of LOG.debug?

I don't think that the 'keep the behavior' principle should overcome
what the messages actually are. The question is: are they warning
messages? The way I see, the messages I changed in this commit to use
the logging system are both debug messages.

Btw, notice that scripts have to take an action to see these messages
anyway, even if it's just calling logging.basicConfig() (which adds by
default the logging.StreamHandler, if no handler is specified).
Meaning that the same behavior will not happen out-of-the-box, even if
we use logging.warn(). So, what your question really asks is if users
should use (at least) logging.basicConfig() or
logging.basicConfig(level=logging.DEBUG) to see those messages.

>
>> +
>> +
>> +class QEMUMachineError(Exception):
>> +    """
>> +    Exception called when an error in QEMUMachine happens.
>> +    """
>> +
>> +
>>  class QEMUMachine(object):
>>      '''A QEMU VM'''
>>
>> @@ -62,18 +72,20 @@ class QEMUMachine(object):
>>          # In iotest.py, the qmp should always use unix socket.
>>          assert self._qmp.is_scm_available()
>>          if self._socket_scm_helper is None:
>> -            print >>sys.stderr, "No path to socket_scm_helper set"
>> -            return -1
>> +            raise QEMUMachineError("No path to socket_scm_helper set")
>>          if os.path.exists(self._socket_scm_helper) == False:
>> -            print >>sys.stderr, "%s does not exist" % self._socket_scm_helper
>> -            return -1
>> +            raise QEMUMachineError("%s does not exist" % self._socket_scm_helper)
>>          fd_param = ["%s" % self._socket_scm_helper,
>>                      "%d" % self._qmp.get_sock_fd(),
>>                      "%s" % fd_file_path]
>>          devnull = open('/dev/null', 'rb')
>> -        p = subprocess.Popen(fd_param, stdin=devnull, stdout=sys.stdout,
>> -                             stderr=sys.stderr)
>> -        return p.wait()
>> +        p = subprocess.Popen(fd_param, stdin=devnull, stdout=subprocess.PIPE,
>> +                             stderr=subprocess.STDOUT)
>> +        output = p.communicate()[0]
>> +        if output:
>> +            LOG.debug(output)
>> +
>> +        return p.returncode
>>
>>      @staticmethod
>>      def _remove_if_exists(path):
>> @@ -154,7 +166,8 @@ class QEMUMachine(object):
>>
>>              exitcode = self._popen.wait()
>>              if exitcode < 0:
>> -                sys.stderr.write('qemu received signal %i: %s\n' % (-exitcode, ' '.join(self._args)))
>> +                LOG.debug('qemu received signal %i: %s', -exitcode,
>> +                          ' '.join(self._args))
>>              self._load_io_log()
>>              self._post_shutdown()
>>
>> --
>> 2.13.5
>>
>
> Fam

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 02/11] qemu.py: avoid writing to stdout/stderr
  2017-08-22 11:11     ` Amador Pahim
@ 2017-08-22 11:56       ` Fam Zheng
  2017-08-22 12:38         ` Amador Pahim
  0 siblings, 1 reply; 24+ messages in thread
From: Fam Zheng @ 2017-08-22 11:56 UTC (permalink / raw)
  To: Amador Pahim
  Cc: Kevin Wolf, Lukáš Doktor, Eduardo Habkost,
	Stefan Hajnoczi, qemu-devel, Max Reitz, Cleber Rosa,
	Markus Armbruster

On Tue, 08/22 13:11, Amador Pahim wrote:
> I don't think that the 'keep the behavior' principle should overcome
> what the messages actually are. The question is: are they warning
> messages? The way I see, the messages I changed in this commit to use
> the logging system are both debug messages.

I think the signal message is a warning.

Fam

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 02/11] qemu.py: avoid writing to stdout/stderr
  2017-08-22 11:56       ` Fam Zheng
@ 2017-08-22 12:38         ` Amador Pahim
  0 siblings, 0 replies; 24+ messages in thread
From: Amador Pahim @ 2017-08-22 12:38 UTC (permalink / raw)
  To: Fam Zheng
  Cc: Kevin Wolf, Lukáš Doktor, Eduardo Habkost,
	Stefan Hajnoczi, qemu-devel, Max Reitz, Cleber Rosa,
	Markus Armbruster

On Tue, Aug 22, 2017 at 1:56 PM, Fam Zheng <famz@redhat.com> wrote:
> On Tue, 08/22 13:11, Amador Pahim wrote:
>> I don't think that the 'keep the behavior' principle should overcome
>> what the messages actually are. The question is: are they warning
>> messages? The way I see, the messages I changed in this commit to use
>> the logging system are both debug messages.
>
> I think the signal message is a warning.

Ok, that's a good reason to change. I will change that one in the next version.
Thanks.

>
> Fam

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 07/11] qemu.py: include debug information on launch error
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 07/11] qemu.py: include debug information on launch error Amador Pahim
@ 2017-08-30 15:55   ` Cleber Rosa
  2017-08-31  1:28     ` Fam Zheng
  2017-08-31  9:47   ` Lukáš Doktor
  1 sibling, 1 reply; 24+ messages in thread
From: Cleber Rosa @ 2017-08-30 15:55 UTC (permalink / raw)
  To: Amador Pahim, qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, ldoktor

[-- Attachment #1: Type: text/plain, Size: 1662 bytes --]



On 08/18/2017 01:05 PM, Amador Pahim wrote:
> When launching a VM, if an exception happens and the VM is not
> initiated, it might be useful to see the qemu command line and
> the qemu command output.
> 
> This patch creates that message. Notice that self._iolog needs to be
> cleaned up in the beginning of the launch() to make sure we will not
> expose the qemu log from a previous launch if the current one fails.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 8 ++++++++
>  1 file changed, 8 insertions(+)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index 0bcec4b3b1..29fd2469f9 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -147,6 +147,7 @@ class QEMUMachine(object):
>  
>      def launch(self):
>          '''Launch the VM and establish a QMP connection'''
> +        self._iolog = None
>          self._qemu_full_args = None
>          devnull = open(os.path.devnull, 'rb')
>          qemulog = open(self._qemu_log_path, 'wb')
> @@ -162,6 +163,13 @@ class QEMUMachine(object):
>              self._post_launch()
>          except:
>              self.shutdown()
> +
> +            LOG.debug('Error launching VM')
> +            if self._qemu_full_args:
> +                LOG.debug('Command: %r', ' '.join(self._qemu_full_args))
> +            if self._iolog:
> +                LOG.debug('Output: %r', self._iolog)
> +

Based on Fam's comment about the signal message being a warning (worth
showing by default), I also think this deserves more than a "debug"
classification.

- Cleber.

>              raise
>  
>      def shutdown(self):
> 


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 04/11] qemu.py: use poll() instead of 'returncode'
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 04/11] qemu.py: use poll() instead of 'returncode' Amador Pahim
@ 2017-08-30 21:10   ` Eduardo Habkost
  0 siblings, 0 replies; 24+ messages in thread
From: Eduardo Habkost @ 2017-08-30 21:10 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, kwolf, ldoktor, famz, stefanha, armbru, mreitz, crosa

On Fri, Aug 18, 2017 at 07:05:19PM +0200, Amador Pahim wrote:
> The 'returncode' Popen attribute is not guaranteed to be updated. It
> actually depends on a call to either poll(), wait() or communicate().
> 
> On the other hand, poll() will: "Check if child process has terminated.
> Set and return returncode attribute."
> 
> Let's use the poll() to check whether the process is running and also
> to get the updated process exit code, when the process is finished.
> 
> As consequence, the shutdown() calls to self._load_io_log()
> self._post_shutdown() are now always executed to make sure we cleanup
> even if VM is not running when the shutdown() is called.

I suggest moving the shutdown() changes to a separate patch.

> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 19 +++++++++++++------
>  1 file changed, 13 insertions(+), 6 deletions(-)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index 51545f7f97..774f971f69 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -98,12 +98,12 @@ class QEMUMachine(object):
>              raise
>  
>      def is_running(self):
> -        return self._popen is not None and self._popen.returncode is None
> +        return self._popen is not None and self._popen.poll() is None
>  
>      def exitcode(self):
>          if self._popen is None:
>              return None
> -        return self._popen.returncode
> +        return self._popen.poll()
>  
>      def get_pid(self):
>          if not self.is_running():
> @@ -111,8 +111,15 @@ class QEMUMachine(object):
>          return self._popen.pid
>  
>      def _load_io_log(self):
> -        with open(self._qemu_log_path, "r") as fh:
> -            self._iolog = fh.read()
> +        '''
> +        Load the Qemu log file content (if available) into the proper
> +        instance variable
> +        '''
> +        try:
> +            with open(self._qemu_log_path, "r") as fh:
> +                self._iolog = fh.read()
> +        except IOError:
> +            pass

Is this really supposed to be included in this patch?  This
change in the _load_io_log() behavior is the most dangerous part
of this patch, and not described in the commit message at all.

I don't think it's a good idea to remove errors unconditionally
here.  The launch() code controls of the creation of the log file
completely, we don't even need to try to load the file if we know
it was not created yet.


>  
>      def _base_args(self):
>          if isinstance(self._monitor_address, tuple):
> @@ -168,8 +175,8 @@ class QEMUMachine(object):
>              if exitcode < 0:
>                  LOG.debug('qemu received signal %i: %s', -exitcode,
>                            ' '.join(self._args))
> -            self._load_io_log()
> -            self._post_shutdown()
> +        self._load_io_log()
> +        self._post_shutdown()
>  
>      underscore_to_dash = string.maketrans('_', '-')
>      def qmp(self, cmd, conv_keys=True, **args):
> -- 
> 2.13.5
> 
> 

-- 
Eduardo

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 07/11] qemu.py: include debug information on launch error
  2017-08-30 15:55   ` Cleber Rosa
@ 2017-08-31  1:28     ` Fam Zheng
  0 siblings, 0 replies; 24+ messages in thread
From: Fam Zheng @ 2017-08-31  1:28 UTC (permalink / raw)
  To: Cleber Rosa
  Cc: Amador Pahim, qemu-devel, stefanha, berrange, ehabkost, mreitz,
	kwolf, armbru, ldoktor

On Wed, 08/30 11:55, Cleber Rosa wrote:
> 
> 
> On 08/18/2017 01:05 PM, Amador Pahim wrote:
> > When launching a VM, if an exception happens and the VM is not
> > initiated, it might be useful to see the qemu command line and
> > the qemu command output.
> > 
> > This patch creates that message. Notice that self._iolog needs to be
> > cleaned up in the beginning of the launch() to make sure we will not
> > expose the qemu log from a previous launch if the current one fails.
> > 
> > Signed-off-by: Amador Pahim <apahim@redhat.com>
> > ---
> >  scripts/qemu.py | 8 ++++++++
> >  1 file changed, 8 insertions(+)
> > 
> > diff --git a/scripts/qemu.py b/scripts/qemu.py
> > index 0bcec4b3b1..29fd2469f9 100644
> > --- a/scripts/qemu.py
> > +++ b/scripts/qemu.py
> > @@ -147,6 +147,7 @@ class QEMUMachine(object):
> >  
> >      def launch(self):
> >          '''Launch the VM and establish a QMP connection'''
> > +        self._iolog = None
> >          self._qemu_full_args = None
> >          devnull = open(os.path.devnull, 'rb')
> >          qemulog = open(self._qemu_log_path, 'wb')
> > @@ -162,6 +163,13 @@ class QEMUMachine(object):
> >              self._post_launch()
> >          except:
> >              self.shutdown()
> > +
> > +            LOG.debug('Error launching VM')
> > +            if self._qemu_full_args:
> > +                LOG.debug('Command: %r', ' '.join(self._qemu_full_args))
> > +            if self._iolog:
> > +                LOG.debug('Output: %r', self._iolog)
> > +
> 
> Based on Fam's comment about the signal message being a warning (worth
> showing by default), I also think this deserves more than a "debug"
> classification.

Yes, LOG.error, please.

Fam

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 07/11] qemu.py: include debug information on launch error
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 07/11] qemu.py: include debug information on launch error Amador Pahim
  2017-08-30 15:55   ` Cleber Rosa
@ 2017-08-31  9:47   ` Lukáš Doktor
  1 sibling, 0 replies; 24+ messages in thread
From: Lukáš Doktor @ 2017-08-31  9:47 UTC (permalink / raw)
  To: Amador Pahim, qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa

[-- Attachment #1: Type: text/plain, Size: 2381 bytes --]

Dne 18.8.2017 v 19:05 Amador Pahim napsal(a):
> When launching a VM, if an exception happens and the VM is not
> initiated, it might be useful to see the qemu command line and
> the qemu command output.
> 
> This patch creates that message. Notice that self._iolog needs to be
> cleaned up in the beginning of the launch() to make sure we will not
> expose the qemu log from a previous launch if the current one fails.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 8 ++++++++
>  1 file changed, 8 insertions(+)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index 0bcec4b3b1..29fd2469f9 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -147,6 +147,7 @@ class QEMUMachine(object):
>  
>      def launch(self):
>          '''Launch the VM and establish a QMP connection'''
> +        self._iolog = None
>          self._qemu_full_args = None
>          devnull = open(os.path.devnull, 'rb')
>          qemulog = open(self._qemu_log_path, 'wb')
> @@ -162,6 +163,13 @@ class QEMUMachine(object):
>              self._post_launch()
>          except:
>              self.shutdown()
> +
> +            LOG.debug('Error launching VM')
> +            if self._qemu_full_args:
> +                LOG.debug('Command: %r', ' '.join(self._qemu_full_args))
> +            if self._iolog:
> +                LOG.debug('Output: %r', self._iolog)
> +
>              raise
>  

I don't want to open the cave, but anybody else would actually prefer custom Exception with the qemu_full_args, iolog and details about the original exception to this? Users who don't care would see/log all the details from the `exception.__str__` and those who are interested in the original exception would query for it eg. via `exception.original_exception`.

Anyway even this change is IMO step into the right direction and we can (and should) refine the use of exceptions in following patches (as Markus spotted, pure Exceptions and other ugliness lives in those waters).

As for the debug vs. error I'd actually stick to "debug", because in negative testing the logged message is only an expected debug and in positive testing it expands the knowledge of the flow, but the actual error message should come from the exception. Not a strong opinion, though...

Regards,
Lukáš

>      def shutdown(self):
> 



[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 502 bytes --]

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups
  2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (10 preceding siblings ...)
  2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 11/11] qemu.py: refactor launch() Amador Pahim
@ 2017-08-31 23:36 ` Eduardo Habkost
  2017-09-01  8:56   ` Amador Pahim
  11 siblings, 1 reply; 24+ messages in thread
From: Eduardo Habkost @ 2017-08-31 23:36 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, kwolf, ldoktor, famz, stefanha, armbru, mreitz, crosa

I was going to queue most of this series except patch 02/11 due
the "qemu received signal" message log level, but a few conflicts
prevent the rest of the series from applying cleanly.  Are you
planning to send v8?

On Fri, Aug 18, 2017 at 07:05:15PM +0200, Amador Pahim wrote:
> Changes v1->v2:
>  - Style fixes to make checkpatch.pl happy.
>  - Rebased.
> Changes v2->v3:
>  - Fix typo in patch 3 ("qemu.py: make 'args' public") commit message.
> Changes v3->v4:
>  - Squash the 2 first commits since they are co-dependant.
>  - Cleanup launch() and shutdown().
>  - Reorder the commits, putting the rename of self._args first.
>  - Rebased.
> Changes v4->v5:
>  - Break the cleanup commit into logical changes and include in the
>    commit messages the rationale for making them.
> Changes v5->v6:
>  - Remove the commit to rename self._args.
>  - Fix is_running() return before first call to maunch().
>  - Use python logging system.
>  - Include the full command line on negative exit code error message.
>  - Use os.path.null instead of /dev/null.
>  - Improve the control over the created/deleted files. 
> Changes v6->v7:
>  - Split commits in self-contained/atomic changes.
>  - Addressed the comments from previous version, basically improving the
>    logging messages and the control over created files. See individual
>    commit messages for details.
> 
> Amador Pahim (11):
>   qemu.py: fix is_running() return before first launch()
>   qemu.py: avoid writing to stdout/stderr
>   qemu.py: use os.path.null instead of /dev/null
>   qemu.py: use poll() instead of 'returncode'
>   qemu.py: cleanup redundant calls in launch()
>   qemu.py: improve message on negative exit code
>   qemu.py: include debug information on launch error
>   qemu.py: make sure we only remove files we create
>   qemu.py: launch vm only if it's not running
>   qemu.py: don't launch again before shutdown()
>   qemu.py: refactor launch()
> 
>  scripts/qemu.py | 141 ++++++++++++++++++++++++++++++++++++++++++--------------
>  1 file changed, 106 insertions(+), 35 deletions(-)
> 
> -- 
> 2.13.5
> 
> 

-- 
Eduardo

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups
  2017-08-31 23:36 ` [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Eduardo Habkost
@ 2017-09-01  8:56   ` Amador Pahim
  0 siblings, 0 replies; 24+ messages in thread
From: Amador Pahim @ 2017-09-01  8:56 UTC (permalink / raw)
  To: Eduardo Habkost
  Cc: qemu-devel, Kevin Wolf, Lukáš Doktor, Fam Zheng,
	Stefan Hajnoczi, Markus Armbruster, Max Reitz, Cleber Rosa

On Fri, Sep 1, 2017 at 1:36 AM, Eduardo Habkost <ehabkost@redhat.com> wrote:
> I was going to queue most of this series except patch 02/11 due
> the "qemu received signal" message log level, but a few conflicts
> prevent the rest of the series from applying cleanly.  Are you
> planning to send v8?

Now I am. Sending asap.

>
> On Fri, Aug 18, 2017 at 07:05:15PM +0200, Amador Pahim wrote:
>> Changes v1->v2:
>>  - Style fixes to make checkpatch.pl happy.
>>  - Rebased.
>> Changes v2->v3:
>>  - Fix typo in patch 3 ("qemu.py: make 'args' public") commit message.
>> Changes v3->v4:
>>  - Squash the 2 first commits since they are co-dependant.
>>  - Cleanup launch() and shutdown().
>>  - Reorder the commits, putting the rename of self._args first.
>>  - Rebased.
>> Changes v4->v5:
>>  - Break the cleanup commit into logical changes and include in the
>>    commit messages the rationale for making them.
>> Changes v5->v6:
>>  - Remove the commit to rename self._args.
>>  - Fix is_running() return before first call to maunch().
>>  - Use python logging system.
>>  - Include the full command line on negative exit code error message.
>>  - Use os.path.null instead of /dev/null.
>>  - Improve the control over the created/deleted files.
>> Changes v6->v7:
>>  - Split commits in self-contained/atomic changes.
>>  - Addressed the comments from previous version, basically improving the
>>    logging messages and the control over created files. See individual
>>    commit messages for details.
>>
>> Amador Pahim (11):
>>   qemu.py: fix is_running() return before first launch()
>>   qemu.py: avoid writing to stdout/stderr
>>   qemu.py: use os.path.null instead of /dev/null
>>   qemu.py: use poll() instead of 'returncode'
>>   qemu.py: cleanup redundant calls in launch()
>>   qemu.py: improve message on negative exit code
>>   qemu.py: include debug information on launch error
>>   qemu.py: make sure we only remove files we create
>>   qemu.py: launch vm only if it's not running
>>   qemu.py: don't launch again before shutdown()
>>   qemu.py: refactor launch()
>>
>>  scripts/qemu.py | 141 ++++++++++++++++++++++++++++++++++++++++++--------------
>>  1 file changed, 106 insertions(+), 35 deletions(-)
>>
>> --
>> 2.13.5
>>
>>
>
> --
> Eduardo

^ permalink raw reply	[flat|nested] 24+ messages in thread

end of thread, other threads:[~2017-09-01  8:56 UTC | newest]

Thread overview: 24+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-08-18 17:05 [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Amador Pahim
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 01/11] qemu.py: fix is_running() return before first launch() Amador Pahim
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 02/11] qemu.py: avoid writing to stdout/stderr Amador Pahim
2017-08-22 10:24   ` Fam Zheng
2017-08-22 11:11     ` Amador Pahim
2017-08-22 11:56       ` Fam Zheng
2017-08-22 12:38         ` Amador Pahim
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 03/11] qemu.py: use os.path.null instead of /dev/null Amador Pahim
2017-08-22 10:24   ` Fam Zheng
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 04/11] qemu.py: use poll() instead of 'returncode' Amador Pahim
2017-08-30 21:10   ` Eduardo Habkost
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 05/11] qemu.py: cleanup redundant calls in launch() Amador Pahim
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 06/11] qemu.py: improve message on negative exit code Amador Pahim
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 07/11] qemu.py: include debug information on launch error Amador Pahim
2017-08-30 15:55   ` Cleber Rosa
2017-08-31  1:28     ` Fam Zheng
2017-08-31  9:47   ` Lukáš Doktor
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 08/11] qemu.py: make sure we only remove files we create Amador Pahim
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 09/11] qemu.py: launch vm only if it's not running Amador Pahim
2017-08-22 10:37   ` Fam Zheng
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 10/11] qemu.py: don't launch again before shutdown() Amador Pahim
2017-08-18 17:05 ` [Qemu-devel] [PATCH v7 11/11] qemu.py: refactor launch() Amador Pahim
2017-08-31 23:36 ` [Qemu-devel] [PATCH v7 00/11] scripts/qemu.py fixes and cleanups Eduardo Habkost
2017-09-01  8:56   ` Amador Pahim

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.