All of lore.kernel.org
 help / color / mirror / Atom feed
* [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups
@ 2017-07-25 17:10 Amador Pahim
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 1/6] qemu.py: make 'args' public Amador Pahim
                   ` (6 more replies)
  0 siblings, 7 replies; 22+ messages in thread
From: Amador Pahim @ 2017-07-25 17:10 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

First commit renames self._args to self.args. The leading underscore
represents that the variable is private and as such it should not be
accessed on instances. But that variable is the main API for inclusion
of Qemu command arguments, so the rename makes it public.

Next commits contain a series of fixes and cleanups to make sure we are
correctly trying to launch the VM and properly shutting it down. More
details about the changes in the individual commit messages.

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.

Amador Pahim (6):
  qemu.py: make 'args' public
  qemu.py: use poll() instead of 'returncode'
  qemu.py: cleanup message on negative exit code
  qemu.py: cleanup launch()
  qemu.py: make sure shutdown() is called before launching again
  qemu.py: include qemu command line and output on launch error

 scripts/qemu.py               | 72 ++++++++++++++++++++++++++++---------------
 tests/qemu-iotests/iotests.py | 18 +++++------
 2 files changed, 57 insertions(+), 33 deletions(-)

-- 
2.13.3

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

* [Qemu-devel] [PATCH v5 1/6] qemu.py: make 'args' public
  2017-07-25 17:10 [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups Amador Pahim
@ 2017-07-25 17:10 ` Amador Pahim
  2017-07-27 14:18   ` Stefan Hajnoczi
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 2/6] qemu.py: use poll() instead of 'returncode' Amador Pahim
                   ` (5 subsequent siblings)
  6 siblings, 1 reply; 22+ messages in thread
From: Amador Pahim @ 2017-07-25 17:10 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

Let's make args public so users can extend it in instances
without feeling like abusing the internal API.

Signed-off-by: Amador Pahim <apahim@redhat.com>
---
 scripts/qemu.py               | 14 +++++++-------
 tests/qemu-iotests/iotests.py | 18 +++++++++---------
 2 files changed, 16 insertions(+), 16 deletions(-)

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 880e3e8219..59ed5270f8 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -33,7 +33,7 @@ class QEMUMachine(object):
         self._qemu_log_path = os.path.join(test_dir, name + ".log")
         self._popen = None
         self._binary = binary
-        self._args = list(args) # Force copy args in case we modify them
+        self.args = list(args) # Force copy args in case we modify them
         self._wrapper = wrapper
         self._events = []
         self._iolog = None
@@ -43,8 +43,8 @@ class QEMUMachine(object):
     # This can be used to add an unused monitor instance.
     def add_monitor_telnet(self, ip, port):
         args = 'tcp:%s:%d,server,nowait,telnet' % (ip, port)
-        self._args.append('-monitor')
-        self._args.append(args)
+        self.args.append('-monitor')
+        self.args.append(args)
 
     def add_fd(self, fd, fdset, opaque, opts=''):
         '''Pass a file descriptor to the VM'''
@@ -54,8 +54,8 @@ class QEMUMachine(object):
         if opts:
             options.append(opts)
 
-        self._args.append('-add-fd')
-        self._args.append(','.join(options))
+        self.args.append('-add-fd')
+        self.args.append(','.join(options))
         return self
 
     def send_fd_scm(self, fd_file_path):
@@ -131,7 +131,7 @@ class QEMUMachine(object):
         qemulog = open(self._qemu_log_path, 'wb')
         try:
             self._pre_launch()
-            args = self._wrapper + [self._binary] + self._base_args() + self._args
+            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._post_launch()
@@ -154,7 +154,7 @@ class QEMUMachine(object):
 
             exitcode = self._popen.wait()
             if exitcode < 0:
-                sys.stderr.write('qemu received signal %i: %s\n' % (-exitcode, ' '.join(self._args)))
+                sys.stderr.write('qemu received signal %i: %s\n' % (-exitcode, ' '.join(self.args)))
             self._load_io_log()
             self._post_shutdown()
 
diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py
index abcf3c10e2..6925d8841e 100644
--- a/tests/qemu-iotests/iotests.py
+++ b/tests/qemu-iotests/iotests.py
@@ -150,13 +150,13 @@ class VM(qtest.QEMUQtestMachine):
         self._num_drives = 0
 
     def add_device(self, opts):
-        self._args.append('-device')
-        self._args.append(opts)
+        self.args.append('-device')
+        self.args.append(opts)
         return self
 
     def add_drive_raw(self, opts):
-        self._args.append('-drive')
-        self._args.append(opts)
+        self.args.append('-drive')
+        self.args.append(opts)
         return self
 
     def add_drive(self, path, opts='', interface='virtio', format=imgfmt):
@@ -172,17 +172,17 @@ class VM(qtest.QEMUQtestMachine):
         if opts:
             options.append(opts)
 
-        self._args.append('-drive')
-        self._args.append(','.join(options))
+        self.args.append('-drive')
+        self.args.append(','.join(options))
         self._num_drives += 1
         return self
 
     def add_blockdev(self, opts):
-        self._args.append('-blockdev')
+        self.args.append('-blockdev')
         if isinstance(opts, str):
-            self._args.append(opts)
+            self.args.append(opts)
         else:
-            self._args.append(','.join(opts))
+            self.args.append(','.join(opts))
         return self
 
     def pause_drive(self, drive, event=None):
-- 
2.13.3

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

* [Qemu-devel] [PATCH v5 2/6] qemu.py: use poll() instead of 'returncode'
  2017-07-25 17:10 [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups Amador Pahim
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 1/6] qemu.py: make 'args' public Amador Pahim
@ 2017-07-25 17:10 ` Amador Pahim
  2017-07-27 14:11   ` Stefan Hajnoczi
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code Amador Pahim
                   ` (4 subsequent siblings)
  6 siblings, 1 reply; 22+ messages in thread
From: Amador Pahim @ 2017-07-25 17:10 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, if any.

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 59ed5270f8..f37e2fe58e 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -86,12 +86,12 @@ class QEMUMachine(object):
             raise
 
     def is_running(self):
-        return self._popen and (self._popen.returncode is None)
+        return self._popen 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():
-- 
2.13.3

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

* [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code
  2017-07-25 17:10 [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups Amador Pahim
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 1/6] qemu.py: make 'args' public Amador Pahim
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 2/6] qemu.py: use poll() instead of 'returncode' Amador Pahim
@ 2017-07-25 17:10 ` Amador Pahim
  2017-07-25 19:08   ` Cleber Rosa
                     ` (2 more replies)
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 4/6] qemu.py: cleanup launch() Amador Pahim
                   ` (3 subsequent siblings)
  6 siblings, 3 replies; 22+ messages in thread
From: Amador Pahim @ 2017-07-25 17:10 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

The message contains the self._args, which has only part of the
options used in the qemu command line and is not representative
enough to figure out what happened to the process.

This patch drops the self._args part of the message.

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

diff --git a/scripts/qemu.py b/scripts/qemu.py
index f37e2fe58e..56142ed59b 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -154,7 +154,8 @@ class QEMUMachine(object):
 
             exitcode = self._popen.wait()
             if exitcode < 0:
-                sys.stderr.write('qemu received signal %i: %s\n' % (-exitcode, ' '.join(self.args)))
+                sys.stderr.write('qemu received signal %i\n' % -exitcode)
+
             self._load_io_log()
             self._post_shutdown()
 
-- 
2.13.3

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

* [Qemu-devel] [PATCH v5 4/6] qemu.py: cleanup launch()
  2017-07-25 17:10 [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (2 preceding siblings ...)
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code Amador Pahim
@ 2017-07-25 17:10 ` Amador Pahim
  2017-07-25 19:17   ` Cleber Rosa
  2017-07-25 20:42   ` Eduardo Habkost
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 5/6] qemu.py: make sure shutdown() is called before launching again Amador Pahim
                   ` (2 subsequent siblings)
  6 siblings, 2 replies; 22+ messages in thread
From: Amador Pahim @ 2017-07-25 17:10 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

launch() is currently taking care of a number of flows, each one if its
own exception treatment, depending on the VM state and the files
creation state.

This patch makes launch() more resilient, off-loading the core calls to
the new _launch() and calling shutdown() if any exception is raised by
_launch(), making sure VM will be terminated and cleaned up.

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

diff --git a/scripts/qemu.py b/scripts/qemu.py
index 56142ed59b..45a63e8e9d 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -99,8 +99,11 @@ 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()
+        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):
@@ -126,23 +129,28 @@ class QEMUMachine(object):
         self._remove_if_exists(self._qemu_log_path)
 
     def launch(self):
-        '''Launch the VM and establish a QMP connection'''
-        devnull = open('/dev/null', 'rb')
-        qemulog = open(self._qemu_log_path, 'wb')
+        '''
+        Try to launch the VM and make sure we cleanup on exception.
+        '''
+        if self.is_running():
+            return
+
         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._post_launch()
+            self._launch()
         except:
-            if self.is_running():
-                self._popen.kill()
-                self._popen.wait()
-            self._load_io_log()
-            self._post_shutdown()
+            self.shutdown()
             raise
 
+    def _launch(self):
+        '''Launch the VM and establish a QMP connection.'''
+        devnull = open('/dev/null', 'rb')
+        qemulog = open(self._qemu_log_path, 'wb')
+        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._post_launch()
+
     def shutdown(self):
         '''Terminate the VM and clean up'''
         if self.is_running():
@@ -156,8 +164,8 @@ class QEMUMachine(object):
             if exitcode < 0:
                 sys.stderr.write('qemu received signal %i\n' % -exitcode)
 
-            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.3

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

* [Qemu-devel] [PATCH v5 5/6] qemu.py: make sure shutdown() is called before launching again
  2017-07-25 17:10 [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (3 preceding siblings ...)
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 4/6] qemu.py: cleanup launch() Amador Pahim
@ 2017-07-25 17:10 ` Amador Pahim
  2017-07-25 19:58   ` Eduardo Habkost
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 6/6] qemu.py: include qemu command line and output on launch error Amador Pahim
  2017-07-27 13:31 ` [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups no-reply
  6 siblings, 1 reply; 22+ messages in thread
From: Amador Pahim @ 2017-07-25 17:10 UTC (permalink / raw)
  To: qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, crosa,
	ldoktor, Amador Pahim

If launch() is called twice or if the VM is terminated not using
shutdown(), the new call to launch() will fail due to the dirty
environment, with files from the previous instance laying around.

This patch add to launch() the ability to check whether shutdown() was
called after a previous launch(), calling it when applies.

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 45a63e8e9d..e18e8ec657 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -39,6 +39,7 @@ class QEMUMachine(object):
         self._iolog = None
         self._socket_scm_helper = socket_scm_helper
         self._debug = debug
+        self._shutdown_pending = False
 
     # This can be used to add an unused monitor instance.
     def add_monitor_telnet(self, ip, port):
@@ -135,8 +136,14 @@ class QEMUMachine(object):
         if self.is_running():
             return
 
+        if self._shutdown_pending:
+            sys.stderr.write('shutdown() was not called after previous '
+                             'launch(). Calling now.\n')
+            self.shutdown()
+
         try:
             self._launch()
+            self._shutdown_pending = True
         except:
             self.shutdown()
             raise
@@ -166,6 +173,7 @@ class QEMUMachine(object):
 
         self._load_io_log()
         self._post_shutdown()
+        self._shutdown_pending = False
 
     underscore_to_dash = string.maketrans('_', '-')
     def qmp(self, cmd, conv_keys=True, **args):
-- 
2.13.3

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

* [Qemu-devel] [PATCH v5 6/6] qemu.py: include qemu command line and output on launch error
  2017-07-25 17:10 [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (4 preceding siblings ...)
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 5/6] qemu.py: make sure shutdown() is called before launching again Amador Pahim
@ 2017-07-25 17:10 ` Amador Pahim
  2017-07-25 21:17   ` Eduardo Habkost
  2017-07-27 13:31 ` [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups no-reply
  6 siblings, 1 reply; 22+ messages in thread
From: Amador Pahim @ 2017-07-25 17:10 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 is useful to see the qemu command line that was executed
and the output of that command.

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

diff --git a/scripts/qemu.py b/scripts/qemu.py
index e18e8ec657..abfa3eebe9 100644
--- a/scripts/qemu.py
+++ b/scripts/qemu.py
@@ -131,7 +131,8 @@ class QEMUMachine(object):
 
     def launch(self):
         '''
-        Try to launch the VM and make sure we cleanup on exception.
+        Try to launch the VM and make sure we cleanup and expose the
+        command line/output in case of exception.
         '''
         if self.is_running():
             return
@@ -142,18 +143,24 @@ class QEMUMachine(object):
             self.shutdown()
 
         try:
-            self._launch()
+            args = None
+            args = self._wrapper + [self._binary] + self._base_args() + self._args
+            self._launch(args)
             self._shutdown_pending = True
         except:
             self.shutdown()
+            sys.stderr.write('Error launching VM.\n%s%s' %
+                             ('Command:\n%s\n' %
+                              ' '.join(args) if args else '',
+                              'Output:\n%s\n' %
+                              ''.join(self._iolog) if self._iolog else ''))
             raise
 
-    def _launch(self):
+    def _launch(self, args):
         '''Launch the VM and establish a QMP connection.'''
         devnull = open('/dev/null', 'rb')
         qemulog = open(self._qemu_log_path, 'wb')
         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._post_launch()
-- 
2.13.3

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

* Re: [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code Amador Pahim
@ 2017-07-25 19:08   ` Cleber Rosa
  2017-07-25 19:51   ` Eduardo Habkost
  2017-07-27 14:12   ` Stefan Hajnoczi
  2 siblings, 0 replies; 22+ messages in thread
From: Cleber Rosa @ 2017-07-25 19:08 UTC (permalink / raw)
  To: Amador Pahim, qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, ldoktor

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



On 07/25/2017 01:10 PM, Amador Pahim wrote:
> The message contains the self._args, which has only part of the
> options used in the qemu command line and is not representative
> enough to figure out what happened to the process.
> 
> This patch drops the self._args part of the message.
> 

Since this patch comes after the proposed "self._args" rename, it should
use the new name.

> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 3 ++-
>  1 file changed, 2 insertions(+), 1 deletion(-)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index f37e2fe58e..56142ed59b 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -154,7 +154,8 @@ class QEMUMachine(object):
>  
>              exitcode = self._popen.wait()
>              if exitcode < 0:
> -                sys.stderr.write('qemu received signal %i: %s\n' % (-exitcode, ' '.join(self.args)))
> +                sys.stderr.write('qemu received signal %i\n' % -exitcode)
> +
>              self._load_io_log()
>              self._post_shutdown()
>  
> 

-- 
Cleber Rosa
[ Sr Software Engineer - Virtualization Team - Red Hat ]
[ Avocado Test Framework - avocado-framework.github.io ]
[  7ABB 96EB 8B46 B94D 5E0F  E9BB 657E 8D33 A5F2 09F3  ]


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

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

* Re: [Qemu-devel] [PATCH v5 4/6] qemu.py: cleanup launch()
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 4/6] qemu.py: cleanup launch() Amador Pahim
@ 2017-07-25 19:17   ` Cleber Rosa
  2017-07-25 20:42   ` Eduardo Habkost
  1 sibling, 0 replies; 22+ messages in thread
From: Cleber Rosa @ 2017-07-25 19:17 UTC (permalink / raw)
  To: Amador Pahim, qemu-devel
  Cc: stefanha, famz, berrange, ehabkost, mreitz, kwolf, armbru, ldoktor

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



On 07/25/2017 01:10 PM, Amador Pahim wrote:
> launch() is currently taking care of a number of flows, each one if its
> own exception treatment, depending on the VM state and the files
> creation state.
> 
> This patch makes launch() more resilient, off-loading the core calls to
> the new _launch() and calling shutdown() if any exception is raised by
> _launch(), making sure VM will be terminated and cleaned up.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 42 +++++++++++++++++++++++++-----------------
>  1 file changed, 25 insertions(+), 17 deletions(-)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index 56142ed59b..45a63e8e9d 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -99,8 +99,11 @@ 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()
> +        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):
> @@ -126,23 +129,28 @@ class QEMUMachine(object):
>          self._remove_if_exists(self._qemu_log_path)
>  
>      def launch(self):
> -        '''Launch the VM and establish a QMP connection'''
> -        devnull = open('/dev/null', 'rb')
> -        qemulog = open(self._qemu_log_path, 'wb')
> +        '''
> +        Try to launch the VM and make sure we cleanup on exception.
> +        '''
> +        if self.is_running():
> +            return
> +
>          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._post_launch()
> +            self._launch()
>          except:
> -            if self.is_running():
> -                self._popen.kill()
> -                self._popen.wait()
> -            self._load_io_log()
> -            self._post_shutdown()
> +            self.shutdown()
>              raise
>  
> +    def _launch(self):
> +        '''Launch the VM and establish a QMP connection.'''
> +        devnull = open('/dev/null', 'rb')

Nitpick: using "os.path.devnull" can improve portability.

- Cleber.

> +        qemulog = open(self._qemu_log_path, 'wb')
> +        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._post_launch()
> +
>      def shutdown(self):
>          '''Terminate the VM and clean up'''
>          if self.is_running():
> @@ -156,8 +164,8 @@ class QEMUMachine(object):
>              if exitcode < 0:
>                  sys.stderr.write('qemu received signal %i\n' % -exitcode)
>  
> -            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):
> 

-- 
Cleber Rosa
[ Sr Software Engineer - Virtualization Team - Red Hat ]
[ Avocado Test Framework - avocado-framework.github.io ]
[  7ABB 96EB 8B46 B94D 5E0F  E9BB 657E 8D33 A5F2 09F3  ]


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

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

* Re: [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code Amador Pahim
  2017-07-25 19:08   ` Cleber Rosa
@ 2017-07-25 19:51   ` Eduardo Habkost
  2017-07-27  8:21     ` Amador Pahim
  2017-07-27 14:12   ` Stefan Hajnoczi
  2 siblings, 1 reply; 22+ messages in thread
From: Eduardo Habkost @ 2017-07-25 19:51 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, stefanha, famz, berrange, mreitz, kwolf, armbru,
	crosa, ldoktor

On Tue, Jul 25, 2017 at 07:10:11PM +0200, Amador Pahim wrote:
> The message contains the self._args, which has only part of the
> options used in the qemu command line and is not representative
> enough to figure out what happened to the process.
> 
> This patch drops the self._args part of the message.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>

I actually think it is a very useful debugging message as is,
because the command-line arguments are often all we need to
reproduce a QEMU crash.

That said, sys.stderr.write doesn't belong to the QEMUMachine
code, as callers should decide if/when/how/where to print
information about a QEMU crash.

I think a QEMUCrashed exception class would be the best way to
report that to callers.  Including the full QEMU command-line on
the exception __str__ method would make it helpful when debugging
crashes: existing code that doesn't catch launch() exceptions
will crash with a more helpful stack trace, and code that already
catches exceptions is probably going to print exception info
somewhere.


> ---
>  scripts/qemu.py | 3 ++-
>  1 file changed, 2 insertions(+), 1 deletion(-)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index f37e2fe58e..56142ed59b 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -154,7 +154,8 @@ class QEMUMachine(object):
>  
>              exitcode = self._popen.wait()
>              if exitcode < 0:
> -                sys.stderr.write('qemu received signal %i: %s\n' % (-exitcode, ' '.join(self.args)))
> +                sys.stderr.write('qemu received signal %i\n' % -exitcode)
> +
>              self._load_io_log()
>              self._post_shutdown()
>  
> -- 
> 2.13.3
> 

-- 
Eduardo

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

* Re: [Qemu-devel] [PATCH v5 5/6] qemu.py: make sure shutdown() is called before launching again
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 5/6] qemu.py: make sure shutdown() is called before launching again Amador Pahim
@ 2017-07-25 19:58   ` Eduardo Habkost
  0 siblings, 0 replies; 22+ messages in thread
From: Eduardo Habkost @ 2017-07-25 19:58 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, stefanha, famz, berrange, mreitz, kwolf, armbru,
	crosa, ldoktor

On Tue, Jul 25, 2017 at 07:10:13PM +0200, Amador Pahim wrote:
> If launch() is called twice or if the VM is terminated not using
> shutdown(), the new call to launch() will fail due to the dirty
> environment, with files from the previous instance laying around.
> 
> This patch add to launch() the ability to check whether shutdown() was
> called after a previous launch(), calling it when applies.
> 
> 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 45a63e8e9d..e18e8ec657 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -39,6 +39,7 @@ class QEMUMachine(object):
>          self._iolog = None
>          self._socket_scm_helper = socket_scm_helper
>          self._debug = debug
> +        self._shutdown_pending = False
>  
>      # This can be used to add an unused monitor instance.
>      def add_monitor_telnet(self, ip, port):
> @@ -135,8 +136,14 @@ class QEMUMachine(object):
>          if self.is_running():
>              return
>  
> +        if self._shutdown_pending:
> +            sys.stderr.write('shutdown() was not called after previous '
> +                             'launch(). Calling now.\n')
> +            self.shutdown()
> +

This looks like obviously invalid API usage.  Why not raise an
Exception?

>          try:
>              self._launch()
> +            self._shutdown_pending = True
>          except:
>              self.shutdown()
>              raise
> @@ -166,6 +173,7 @@ class QEMUMachine(object):
>  
>          self._load_io_log()
>          self._post_shutdown()
> +        self._shutdown_pending = False
>  
>      underscore_to_dash = string.maketrans('_', '-')
>      def qmp(self, cmd, conv_keys=True, **args):
> -- 
> 2.13.3
> 

-- 
Eduardo

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

* Re: [Qemu-devel] [PATCH v5 4/6] qemu.py: cleanup launch()
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 4/6] qemu.py: cleanup launch() Amador Pahim
  2017-07-25 19:17   ` Cleber Rosa
@ 2017-07-25 20:42   ` Eduardo Habkost
  2017-07-27  7:56     ` Amador Pahim
  1 sibling, 1 reply; 22+ messages in thread
From: Eduardo Habkost @ 2017-07-25 20:42 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, stefanha, famz, berrange, mreitz, kwolf, armbru,
	crosa, ldoktor

On Tue, Jul 25, 2017 at 07:10:12PM +0200, Amador Pahim wrote:
> launch() is currently taking care of a number of flows, each one if its
> own exception treatment, depending on the VM state and the files
> creation state.
> 
> This patch makes launch() more resilient, off-loading the core calls to
> the new _launch() and calling shutdown() if any exception is raised by
> _launch(), making sure VM will be terminated and cleaned up.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 42 +++++++++++++++++++++++++-----------------
>  1 file changed, 25 insertions(+), 17 deletions(-)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index 56142ed59b..45a63e8e9d 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -99,8 +99,11 @@ 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()
> +        try:
> +            with open(self._qemu_log_path, "r") as fh:
> +                self._iolog = fh.read()
> +        except IOError:
> +            pass

I don't like the idea of ignoring errors unconditionally.  It's
OK to ignore the file if we are recovering from a crash and
didn't even create it, but it's not OK if we ran QEMU
successfully and we really want to load the log file.

Maybe an optional ignore_errors argument to shutdown() and its
helpers, to tell the shutdown functions that it is really OK to
ignore errors?

>  
>      def _base_args(self):
>          if isinstance(self._monitor_address, tuple):
> @@ -126,23 +129,28 @@ class QEMUMachine(object):
>          self._remove_if_exists(self._qemu_log_path)
>  
>      def launch(self):
> -        '''Launch the VM and establish a QMP connection'''
> -        devnull = open('/dev/null', 'rb')
> -        qemulog = open(self._qemu_log_path, 'wb')

This was moved inside the try block.

This means we may try to read the log file even if we failed to
create it.  This will have funny side-effects if the log file
already existed and we didn't have permissions to write to it.

For example:

  ("/var/tmp/myvm.log" was created by another user)

  >>> m = qemu.QEMUMachine(binary='/usr/bin/qemu-system-x86_64', name='myvm')
  >>> m.launch()
  Traceback (most recent call last):
    File "<stdin>", line 1, in <module>
    File "qemu.py", line 151, in launch
      self.shutdown()
    File "qemu.py", line 182, in shutdown
      self._post_shutdown()
    File "qemu.py", line 130, in _post_shutdown
      self._remove_if_exists(self._qemu_log_path)
    File "qemu.py", line 83, in _remove_if_exists
      os.remove(path)
  OSError: [Errno 1] Operation not permitted: '/var/tmp/myvm.log'
  >>> m.get_log()
  'old log file\n'
  >>> 


> +        '''
> +        Try to launch the VM and make sure we cleanup on exception.
> +        '''
> +        if self.is_running():
> +            return

Why exactly is this necessary?

Calling launch() twice is likely to be a mistake (e.g. what if
self.args was changed?).  I would raise an Exception instead.


> +
>          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._post_launch()
> +            self._launch()
>          except:
> -            if self.is_running():
> -                self._popen.kill()
> -                self._popen.wait()
> -            self._load_io_log()
> -            self._post_shutdown()

> +            self.shutdown()
>              raise
>  
> +    def _launch(self):
> +        '''Launch the VM and establish a QMP connection.'''
> +        devnull = open('/dev/null', 'rb')
> +        qemulog = open(self._qemu_log_path, 'wb')
> +        self._pre_launch()
> +        args = self._wrapper + [self._binary] + self._base_args() + self._args

This looks broken:

  >>> m.launch()
  Error launching VM.
  Traceback (most recent call last):
    File "<stdin>", line 1, in <module>
    File "qemu.py", line 147, in launch
      args = self._wrapper + [self._binary] + self._base_args() + self._args
  AttributeError: 'QEMUMachine' object has no attribute '_args'


> +        self._popen = subprocess.Popen(args, stdin=devnull, stdout=qemulog,
> +                                       stderr=subprocess.STDOUT, shell=False)
> +        self._post_launch()
> +
>      def shutdown(self):
>          '''Terminate the VM and clean up'''
>          if self.is_running():
> @@ -156,8 +164,8 @@ class QEMUMachine(object):
>              if exitcode < 0:
>                  sys.stderr.write('qemu received signal %i\n' % -exitcode)
>  
> -            self._load_io_log()
> -            self._post_shutdown()

It looks like the existing code isn't safe, and can call
_post_shutdown() before _post_launch() was called.

What if QEMUQtestMachine._pre_launch() failed because the qtest
socket is already in use by another process?  We shouldn't delete
a socket that doesn't even belong to us.

I suggest setting self._qemu_log_path, self._monitor_address,
self._qtest_path only after the files were really created, and
make _post_shutdown() delete the files only if those attributes
are not None (meaning we will only delete files that we created).


> +        self._load_io_log()
> +        self._post_shutdown()
>  
>      underscore_to_dash = string.maketrans('_', '-')
>      def qmp(self, cmd, conv_keys=True, **args):
> -- 
> 2.13.3
> 

-- 
Eduardo

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

* Re: [Qemu-devel] [PATCH v5 6/6] qemu.py: include qemu command line and output on launch error
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 6/6] qemu.py: include qemu command line and output on launch error Amador Pahim
@ 2017-07-25 21:17   ` Eduardo Habkost
  2017-07-27  8:01     ` Amador Pahim
  0 siblings, 1 reply; 22+ messages in thread
From: Eduardo Habkost @ 2017-07-25 21:17 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, stefanha, famz, berrange, mreitz, kwolf, armbru,
	crosa, ldoktor

On Tue, Jul 25, 2017 at 07:10:14PM +0200, Amador Pahim wrote:
> When launching a VM, if an exception happens and the VM is not
> initiated, it is useful to see the qemu command line that was executed
> and the output of that command.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 15 +++++++++++----
>  1 file changed, 11 insertions(+), 4 deletions(-)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index e18e8ec657..abfa3eebe9 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -131,7 +131,8 @@ class QEMUMachine(object):
>  
>      def launch(self):
>          '''
> -        Try to launch the VM and make sure we cleanup on exception.
> +        Try to launch the VM and make sure we cleanup and expose the
> +        command line/output in case of exception.
>          '''
>          if self.is_running():
>              return
> @@ -142,18 +143,24 @@ class QEMUMachine(object):
>              self.shutdown()
>  
>          try:
> -            self._launch()
> +            args = None
> +            args = self._wrapper + [self._binary] + self._base_args() + self._args
> +            self._launch(args)

I think it would be easier to set a self._full_qemu_args
attribute instead of passing data around through local variables
and method arguments.

>              self._shutdown_pending = True
>          except:
>              self.shutdown()
> +            sys.stderr.write('Error launching VM.\n%s%s' %
> +                             ('Command:\n%s\n' %
> +                              ' '.join(args) if args else '',
> +                              'Output:\n%s\n' %
> +                              ''.join(self._iolog) if self._iolog else ''))

I suggest making this conditional on self._debug.

We could also introduce a QEMULaunchError exception class
containing this info, but I'm unsure if we should raise it on
every exception, or raise more specific custom exceptions on
specific cases (e.g. one exception for QMP timeout, another for
QEMU binary not found, another for QEMU killed by a signal, etc).


>              raise
>  
> -    def _launch(self):
> +    def _launch(self, args):
>          '''Launch the VM and establish a QMP connection.'''
>          devnull = open('/dev/null', 'rb')
>          qemulog = open(self._qemu_log_path, 'wb')
>          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._post_launch()
> -- 
> 2.13.3
> 

-- 
Eduardo

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

* Re: [Qemu-devel] [PATCH v5 4/6] qemu.py: cleanup launch()
  2017-07-25 20:42   ` Eduardo Habkost
@ 2017-07-27  7:56     ` Amador Pahim
  0 siblings, 0 replies; 22+ messages in thread
From: Amador Pahim @ 2017-07-27  7:56 UTC (permalink / raw)
  To: Eduardo Habkost
  Cc: qemu-devel, Stefan Hajnoczi, Fam Zheng, Daniel Berrange,
	Max Reitz, Kevin Wolf, Markus Armbruster, Cleber Rosa,
	Lukáš Doktor

On Tue, Jul 25, 2017 at 10:42 PM, Eduardo Habkost <ehabkost@redhat.com> wrote:
> On Tue, Jul 25, 2017 at 07:10:12PM +0200, Amador Pahim wrote:
>> launch() is currently taking care of a number of flows, each one if its
>> own exception treatment, depending on the VM state and the files
>> creation state.
>>
>> This patch makes launch() more resilient, off-loading the core calls to
>> the new _launch() and calling shutdown() if any exception is raised by
>> _launch(), making sure VM will be terminated and cleaned up.
>>
>> Signed-off-by: Amador Pahim <apahim@redhat.com>
>> ---
>>  scripts/qemu.py | 42 +++++++++++++++++++++++++-----------------
>>  1 file changed, 25 insertions(+), 17 deletions(-)
>>
>> diff --git a/scripts/qemu.py b/scripts/qemu.py
>> index 56142ed59b..45a63e8e9d 100644
>> --- a/scripts/qemu.py
>> +++ b/scripts/qemu.py
>> @@ -99,8 +99,11 @@ 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()
>> +        try:
>> +            with open(self._qemu_log_path, "r") as fh:
>> +                self._iolog = fh.read()
>> +        except IOError:
>> +            pass
>
> I don't like the idea of ignoring errors unconditionally.  It's
> OK to ignore the file if we are recovering from a crash and
> didn't even create it, but it's not OK if we ran QEMU
> successfully and we really want to load the log file.
>
> Maybe an optional ignore_errors argument to shutdown() and its
> helpers, to tell the shutdown functions that it is really OK to
> ignore errors?

The intention was to not crash on a call to _load_io_log) if it
happens after the file is removed. But no strong opinion... it's
indeed incorrect usage and not ignoring that is a way to go.

>
>>
>>      def _base_args(self):
>>          if isinstance(self._monitor_address, tuple):
>> @@ -126,23 +129,28 @@ class QEMUMachine(object):
>>          self._remove_if_exists(self._qemu_log_path)
>>
>>      def launch(self):
>> -        '''Launch the VM and establish a QMP connection'''
>> -        devnull = open('/dev/null', 'rb')
>> -        qemulog = open(self._qemu_log_path, 'wb')
>
> This was moved inside the try block.
>
> This means we may try to read the log file even if we failed to
> create it.  This will have funny side-effects if the log file
> already existed and we didn't have permissions to write to it.

Good point. Let's increase the overall control we have over the files
and better protect the code.

>
> For example:
>
>   ("/var/tmp/myvm.log" was created by another user)
>
>   >>> m = qemu.QEMUMachine(binary='/usr/bin/qemu-system-x86_64', name='myvm')
>   >>> m.launch()
>   Traceback (most recent call last):
>     File "<stdin>", line 1, in <module>
>     File "qemu.py", line 151, in launch
>       self.shutdown()
>     File "qemu.py", line 182, in shutdown
>       self._post_shutdown()
>     File "qemu.py", line 130, in _post_shutdown
>       self._remove_if_exists(self._qemu_log_path)
>     File "qemu.py", line 83, in _remove_if_exists
>       os.remove(path)
>   OSError: [Errno 1] Operation not permitted: '/var/tmp/myvm.log'
>   >>> m.get_log()
>   'old log file\n'
>   >>>
>
>
>> +        '''
>> +        Try to launch the VM and make sure we cleanup on exception.
>> +        '''
>> +        if self.is_running():
>> +            return
>
> Why exactly is this necessary?
>
> Calling launch() twice is likely to be a mistake (e.g. what if
> self.args was changed?).  I would raise an Exception instead.

Ok, raising exception it is.

>
>
>> +
>>          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._post_launch()
>> +            self._launch()
>>          except:
>> -            if self.is_running():
>> -                self._popen.kill()
>> -                self._popen.wait()
>> -            self._load_io_log()
>> -            self._post_shutdown()
>
>> +            self.shutdown()
>>              raise
>>
>> +    def _launch(self):
>> +        '''Launch the VM and establish a QMP connection.'''
>> +        devnull = open('/dev/null', 'rb')
>> +        qemulog = open(self._qemu_log_path, 'wb')
>> +        self._pre_launch()
>> +        args = self._wrapper + [self._binary] + self._base_args() + self._args
>
> This looks broken:
>
>   >>> m.launch()
>   Error launching VM.
>   Traceback (most recent call last):
>     File "<stdin>", line 1, in <module>
>     File "qemu.py", line 147, in launch
>       args = self._wrapper + [self._binary] + self._base_args() + self._args
>   AttributeError: 'QEMUMachine' object has no attribute '_args'

My bad. Leftover after the rename of self._args.

>
>
>> +        self._popen = subprocess.Popen(args, stdin=devnull, stdout=qemulog,
>> +                                       stderr=subprocess.STDOUT, shell=False)
>> +        self._post_launch()
>> +
>>      def shutdown(self):
>>          '''Terminate the VM and clean up'''
>>          if self.is_running():
>> @@ -156,8 +164,8 @@ class QEMUMachine(object):
>>              if exitcode < 0:
>>                  sys.stderr.write('qemu received signal %i\n' % -exitcode)
>>
>> -            self._load_io_log()
>> -            self._post_shutdown()
>
> It looks like the existing code isn't safe, and can call
> _post_shutdown() before _post_launch() was called.
>
> What if QEMUQtestMachine._pre_launch() failed because the qtest
> socket is already in use by another process?  We shouldn't delete
> a socket that doesn't even belong to us.
>
> I suggest setting self._qemu_log_path, self._monitor_address,
> self._qtest_path only after the files were really created, and
> make _post_shutdown() delete the files only if those attributes
> are not None (meaning we will only delete files that we created).

Yes, as I stated before, I'm increasing the control over the files.

>
>
>> +        self._load_io_log()
>> +        self._post_shutdown()
>>
>>      underscore_to_dash = string.maketrans('_', '-')
>>      def qmp(self, cmd, conv_keys=True, **args):
>> --
>> 2.13.3
>>
>
> --
> Eduardo

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

* Re: [Qemu-devel] [PATCH v5 6/6] qemu.py: include qemu command line and output on launch error
  2017-07-25 21:17   ` Eduardo Habkost
@ 2017-07-27  8:01     ` Amador Pahim
  0 siblings, 0 replies; 22+ messages in thread
From: Amador Pahim @ 2017-07-27  8:01 UTC (permalink / raw)
  To: Eduardo Habkost
  Cc: qemu-devel, Stefan Hajnoczi, Fam Zheng, Daniel Berrange,
	Max Reitz, Kevin Wolf, Markus Armbruster, Cleber Rosa,
	Lukáš Doktor

On Tue, Jul 25, 2017 at 11:17 PM, Eduardo Habkost <ehabkost@redhat.com> wrote:
> On Tue, Jul 25, 2017 at 07:10:14PM +0200, Amador Pahim wrote:
>> When launching a VM, if an exception happens and the VM is not
>> initiated, it is useful to see the qemu command line that was executed
>> and the output of that command.
>>
>> Signed-off-by: Amador Pahim <apahim@redhat.com>
>> ---
>>  scripts/qemu.py | 15 +++++++++++----
>>  1 file changed, 11 insertions(+), 4 deletions(-)
>>
>> diff --git a/scripts/qemu.py b/scripts/qemu.py
>> index e18e8ec657..abfa3eebe9 100644
>> --- a/scripts/qemu.py
>> +++ b/scripts/qemu.py
>> @@ -131,7 +131,8 @@ class QEMUMachine(object):
>>
>>      def launch(self):
>>          '''
>> -        Try to launch the VM and make sure we cleanup on exception.
>> +        Try to launch the VM and make sure we cleanup and expose the
>> +        command line/output in case of exception.
>>          '''
>>          if self.is_running():
>>              return
>> @@ -142,18 +143,24 @@ class QEMUMachine(object):
>>              self.shutdown()
>>
>>          try:
>> -            self._launch()
>> +            args = None
>> +            args = self._wrapper + [self._binary] + self._base_args() + self._args
>> +            self._launch(args)
>
> I think it would be easier to set a self._full_qemu_args
> attribute instead of passing data around through local variables
> and method arguments.

Ok, matter of preference. I'm ok with both.

>
>>              self._shutdown_pending = True
>>          except:
>>              self.shutdown()
>> +            sys.stderr.write('Error launching VM.\n%s%s' %
>> +                             ('Command:\n%s\n' %
>> +                              ' '.join(args) if args else '',
>> +                              'Output:\n%s\n' %
>> +                              ''.join(self._iolog) if self._iolog else ''))
>
> I suggest making this conditional on self._debug.

Ok.

>
> We could also introduce a QEMULaunchError exception class
> containing this info, but I'm unsure if we should raise it on
> every exception, or raise more specific custom exceptions on
> specific cases (e.g. one exception for QMP timeout, another for
> QEMU binary not found, another for QEMU killed by a signal, etc).

I'd prefer to keep the original exceptions and make this a debug message.

>
>
>>              raise
>>
>> -    def _launch(self):
>> +    def _launch(self, args):
>>          '''Launch the VM and establish a QMP connection.'''
>>          devnull = open('/dev/null', 'rb')
>>          qemulog = open(self._qemu_log_path, 'wb')
>>          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._post_launch()
>> --
>> 2.13.3
>>
>
> --
> Eduardo

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

* Re: [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code
  2017-07-25 19:51   ` Eduardo Habkost
@ 2017-07-27  8:21     ` Amador Pahim
  2017-07-30 20:24       ` Eduardo Habkost
  0 siblings, 1 reply; 22+ messages in thread
From: Amador Pahim @ 2017-07-27  8:21 UTC (permalink / raw)
  To: Eduardo Habkost
  Cc: qemu-devel, Stefan Hajnoczi, Fam Zheng, Daniel Berrange,
	Max Reitz, Kevin Wolf, Markus Armbruster, Cleber Rosa,
	Lukáš Doktor

On Tue, Jul 25, 2017 at 9:51 PM, Eduardo Habkost <ehabkost@redhat.com> wrote:
> On Tue, Jul 25, 2017 at 07:10:11PM +0200, Amador Pahim wrote:
>> The message contains the self._args, which has only part of the
>> options used in the qemu command line and is not representative
>> enough to figure out what happened to the process.
>>
>> This patch drops the self._args part of the message.
>>
>> Signed-off-by: Amador Pahim <apahim@redhat.com>
>
> I actually think it is a very useful debugging message as is,
> because the command-line arguments are often all we need to
> reproduce a QEMU crash.

The message currently contains only part of the args, not all
(base_args are not included). Let's include the full command then.

>
> That said, sys.stderr.write doesn't belong to the QEMUMachine
> code, as callers should decide if/when/how/where to print
> information about a QEMU crash.
>
> I think a QEMUCrashed exception class would be the best way to
> report that to callers.  Including the full QEMU command-line on
> the exception __str__ method would make it helpful when debugging
> crashes: existing code that doesn't catch launch() exceptions
> will crash with a more helpful stack trace, and code that already
> catches exceptions is probably going to print exception info
> somewhere.

I agree using sys.stderr.write should be avoided, but I'm not
convinced this message should raise an exception. I think it's time to
improve the logging capabilities here.

>
>
>> ---
>>  scripts/qemu.py | 3 ++-
>>  1 file changed, 2 insertions(+), 1 deletion(-)
>>
>> diff --git a/scripts/qemu.py b/scripts/qemu.py
>> index f37e2fe58e..56142ed59b 100644
>> --- a/scripts/qemu.py
>> +++ b/scripts/qemu.py
>> @@ -154,7 +154,8 @@ class QEMUMachine(object):
>>
>>              exitcode = self._popen.wait()
>>              if exitcode < 0:
>> -                sys.stderr.write('qemu received signal %i: %s\n' % (-exitcode, ' '.join(self.args)))
>> +                sys.stderr.write('qemu received signal %i\n' % -exitcode)
>> +
>>              self._load_io_log()
>>              self._post_shutdown()
>>
>> --
>> 2.13.3
>>
>
> --
> Eduardo

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

* Re: [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups
  2017-07-25 17:10 [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups Amador Pahim
                   ` (5 preceding siblings ...)
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 6/6] qemu.py: include qemu command line and output on launch error Amador Pahim
@ 2017-07-27 13:31 ` no-reply
  6 siblings, 0 replies; 22+ messages in thread
From: no-reply @ 2017-07-27 13:31 UTC (permalink / raw)
  To: apahim; +Cc: famz, qemu-devel, kwolf, ldoktor

Hi,

This series seems to have some coding style problems. See output below for
more information:

Type: series
Subject: [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups
Message-id: 20170725171014.25193-1-apahim@redhat.com

=== TEST SCRIPT BEGIN ===
#!/bin/bash

BASE=base
n=1
total=$(git log --oneline $BASE.. | wc -l)
failed=0

git config --local diff.renamelimit 0
git config --local diff.renames True

commits="$(git log --format=%H --reverse $BASE..)"
for c in $commits; do
    echo "Checking PATCH $n/$total: $(git log -n 1 --format=%s $c)..."
    if ! git show $c --format=email | ./scripts/checkpatch.pl --mailback -; then
        failed=1
        echo
    fi
    n=$((n+1))
done

exit $failed
=== TEST SCRIPT END ===

Updating 3c8cf5a9c21ff8782164d1def7f44bd888713384
Switched to a new branch 'test'
04d94fd qemu.py: include qemu command line and output on launch error
70b7dac qemu.py: make sure shutdown() is called before launching again
84b4932 qemu.py: cleanup launch()
c82bab2 qemu.py: cleanup message on negative exit code
333f6d6 qemu.py: use poll() instead of 'returncode'
e2a1825 qemu.py: make 'args' public

=== OUTPUT BEGIN ===
Checking PATCH 1/6: qemu.py: make 'args' public...
WARNING: line over 80 characters
#52: FILE: scripts/qemu.py:134:
+            args = self._wrapper + [self._binary] + self._base_args() + self.args

ERROR: line over 90 characters
#61: FILE: scripts/qemu.py:157:
+                sys.stderr.write('qemu received signal %i: %s\n' % (-exitcode, ' '.join(self.args)))

total: 1 errors, 1 warnings, 83 lines checked

Your patch has style problems, please review.  If any of these errors
are false positives report them to the maintainer, see
CHECKPATCH in MAINTAINERS.

Checking PATCH 2/6: qemu.py: use poll() instead of 'returncode'...
Checking PATCH 3/6: qemu.py: cleanup message on negative exit code...
Checking PATCH 4/6: qemu.py: cleanup launch()...
Checking PATCH 5/6: qemu.py: make sure shutdown() is called before launching again...
Checking PATCH 6/6: qemu.py: include qemu command line and output on launch error...
WARNING: line over 80 characters
#33: FILE: scripts/qemu.py:147:
+            args = self._wrapper + [self._binary] + self._base_args() + self._args

total: 0 errors, 1 warnings, 36 lines checked

Your patch has style problems, please review.  If any of these errors
are false positives report them to the maintainer, see
CHECKPATCH in MAINTAINERS.
=== OUTPUT END ===

Test command exited with code: 1


---
Email generated automatically by Patchew [http://patchew.org/].
Please send your feedback to patchew-devel@freelists.org

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

* Re: [Qemu-devel] [PATCH v5 2/6] qemu.py: use poll() instead of 'returncode'
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 2/6] qemu.py: use poll() instead of 'returncode' Amador Pahim
@ 2017-07-27 14:11   ` Stefan Hajnoczi
  0 siblings, 0 replies; 22+ messages in thread
From: Stefan Hajnoczi @ 2017-07-27 14:11 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, famz, berrange, ehabkost, mreitz, kwolf, armbru,
	crosa, ldoktor

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

On Tue, Jul 25, 2017 at 07:10:10PM +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, if any.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)

Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

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

* Re: [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code Amador Pahim
  2017-07-25 19:08   ` Cleber Rosa
  2017-07-25 19:51   ` Eduardo Habkost
@ 2017-07-27 14:12   ` Stefan Hajnoczi
  2 siblings, 0 replies; 22+ messages in thread
From: Stefan Hajnoczi @ 2017-07-27 14:12 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, famz, berrange, ehabkost, mreitz, kwolf, armbru,
	crosa, ldoktor

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

On Tue, Jul 25, 2017 at 07:10:11PM +0200, Amador Pahim wrote:
> The message contains the self._args, which has only part of the
> options used in the qemu command line and is not representative
> enough to figure out what happened to the process.
> 
> This patch drops the self._args part of the message.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 3 ++-
>  1 file changed, 2 insertions(+), 1 deletion(-)

Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

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

* Re: [Qemu-devel] [PATCH v5 1/6] qemu.py: make 'args' public
  2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 1/6] qemu.py: make 'args' public Amador Pahim
@ 2017-07-27 14:18   ` Stefan Hajnoczi
  2017-07-27 14:59     ` Amador Pahim
  0 siblings, 1 reply; 22+ messages in thread
From: Stefan Hajnoczi @ 2017-07-27 14:18 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, famz, berrange, ehabkost, mreitz, kwolf, armbru,
	crosa, ldoktor

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

On Tue, Jul 25, 2017 at 07:10:09PM +0200, Amador Pahim wrote:
> Let's make args public so users can extend it in instances
> without feeling like abusing the internal API.
> 
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py               | 14 +++++++-------
>  tests/qemu-iotests/iotests.py | 18 +++++++++---------
>  2 files changed, 16 insertions(+), 16 deletions(-)

As discussed in the previous revision, I don't think this patch is
justified because all current users just need a protected field.  There
are no users who need the field to be public so this change is
premature.

Stefan

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

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

* Re: [Qemu-devel] [PATCH v5 1/6] qemu.py: make 'args' public
  2017-07-27 14:18   ` Stefan Hajnoczi
@ 2017-07-27 14:59     ` Amador Pahim
  0 siblings, 0 replies; 22+ messages in thread
From: Amador Pahim @ 2017-07-27 14:59 UTC (permalink / raw)
  To: Stefan Hajnoczi
  Cc: qemu-devel, Fam Zheng, Daniel Berrange, Eduardo Habkost,
	Max Reitz, Kevin Wolf, Markus Armbruster, Cleber Rosa,
	Lukáš Doktor

On Thu, Jul 27, 2017 at 4:18 PM, Stefan Hajnoczi <stefanha@gmail.com> wrote:
> On Tue, Jul 25, 2017 at 07:10:09PM +0200, Amador Pahim wrote:
>> Let's make args public so users can extend it in instances
>> without feeling like abusing the internal API.
>>
>> Signed-off-by: Amador Pahim <apahim@redhat.com>
>> ---
>>  scripts/qemu.py               | 14 +++++++-------
>>  tests/qemu-iotests/iotests.py | 18 +++++++++---------
>>  2 files changed, 16 insertions(+), 16 deletions(-)
>
> As discussed in the previous revision, I don't think this patch is
> justified because all current users just need a protected field.  There
> are no users who need the field to be public so this change is
> premature.

Indeed. It will be removed from the next version.

>
> Stefan

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

* Re: [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code
  2017-07-27  8:21     ` Amador Pahim
@ 2017-07-30 20:24       ` Eduardo Habkost
  0 siblings, 0 replies; 22+ messages in thread
From: Eduardo Habkost @ 2017-07-30 20:24 UTC (permalink / raw)
  To: Amador Pahim
  Cc: qemu-devel, Stefan Hajnoczi, Fam Zheng, Daniel Berrange,
	Max Reitz, Kevin Wolf, Markus Armbruster, Cleber Rosa,
	Lukáš Doktor

On Thu, Jul 27, 2017 at 10:21:22AM +0200, Amador Pahim wrote:
> On Tue, Jul 25, 2017 at 9:51 PM, Eduardo Habkost <ehabkost@redhat.com> wrote:
> > On Tue, Jul 25, 2017 at 07:10:11PM +0200, Amador Pahim wrote:
> >> The message contains the self._args, which has only part of the
> >> options used in the qemu command line and is not representative
> >> enough to figure out what happened to the process.
> >>
> >> This patch drops the self._args part of the message.
> >>
> >> Signed-off-by: Amador Pahim <apahim@redhat.com>
> >
> > I actually think it is a very useful debugging message as is,
> > because the command-line arguments are often all we need to
> > reproduce a QEMU crash.
> 
> The message currently contains only part of the args, not all
> (base_args are not included). Let's include the full command then.
> 
> >
> > That said, sys.stderr.write doesn't belong to the QEMUMachine
> > code, as callers should decide if/when/how/where to print
> > information about a QEMU crash.
> >
> > I think a QEMUCrashed exception class would be the best way to
> > report that to callers.  Including the full QEMU command-line on
> > the exception __str__ method would make it helpful when debugging
> > crashes: existing code that doesn't catch launch() exceptions
> > will crash with a more helpful stack trace, and code that already
> > catches exceptions is probably going to print exception info
> > somewhere.
> 
> I agree using sys.stderr.write should be avoided, but I'm not
> convinced this message should raise an exception. [...]

No problem, we can discuss later when/how to raise exceptions to
indicate specific error cases.

We could make the log message conditional on self._debug by now,
but I don't think it will be a problem if we keep it
unconditional (as QEMU crashes are not supposed to happen under
normal circumstances).

>                                             [...] I think it's time to
> improve the logging capabilities here.

What about using the Python logging module?

-- 
Eduardo

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

end of thread, other threads:[~2017-07-30 20:31 UTC | newest]

Thread overview: 22+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-07-25 17:10 [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups Amador Pahim
2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 1/6] qemu.py: make 'args' public Amador Pahim
2017-07-27 14:18   ` Stefan Hajnoczi
2017-07-27 14:59     ` Amador Pahim
2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 2/6] qemu.py: use poll() instead of 'returncode' Amador Pahim
2017-07-27 14:11   ` Stefan Hajnoczi
2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 3/6] qemu.py: cleanup message on negative exit code Amador Pahim
2017-07-25 19:08   ` Cleber Rosa
2017-07-25 19:51   ` Eduardo Habkost
2017-07-27  8:21     ` Amador Pahim
2017-07-30 20:24       ` Eduardo Habkost
2017-07-27 14:12   ` Stefan Hajnoczi
2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 4/6] qemu.py: cleanup launch() Amador Pahim
2017-07-25 19:17   ` Cleber Rosa
2017-07-25 20:42   ` Eduardo Habkost
2017-07-27  7:56     ` Amador Pahim
2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 5/6] qemu.py: make sure shutdown() is called before launching again Amador Pahim
2017-07-25 19:58   ` Eduardo Habkost
2017-07-25 17:10 ` [Qemu-devel] [PATCH v5 6/6] qemu.py: include qemu command line and output on launch error Amador Pahim
2017-07-25 21:17   ` Eduardo Habkost
2017-07-27  8:01     ` Amador Pahim
2017-07-27 13:31 ` [Qemu-devel] [PATCH v5 0/6] scripts/qemu.py fixes and cleanups no-reply

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.