Re: [Qemu-devel] [PATCH v6 7/7] qemu.py: include debug information on launch error

[Markus Armbruster <armbru@redhat.com>]

Amador Pahim <apahim@redhat.com> writes:

> 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.
>
> Before this patch:
>
>     >>> import qemu
>     >>> vm = qemu.QEMUMachine('qemu-system-aarch64', debug=True)
>     >>> vm.launch()
>     Traceback (most recent call last):
>       File "<stdin>", line 1, in <module>
>       File "qemu.py", line 175, in launch
>         self._launch()
>       File "qemu.py", line 189, in _launch
>         self._post_launch()
>       File "qemu.py", line 154, in _post_launch
>         self._qmp.accept()
>       File "qmp/qmp.py", line 145, in accept
>         self.__sock, _ = self.__sock.accept()
>       File "/usr/lib64/python2.7/socket.py", line 206, in accept
>         sock, addr = self._sock.accept()
>     socket.timeout: timed out
>     >>>
>
> After this patch:
>
>     >>> import qemu
>     >>> vm = qemu.QEMUMachine('qemu-system-aarch64', debug=True)
>     >>> vm.launch()
>     DEBUG:qemu:Error launching VM. Command: 'qemu-system-aarch64
>     -chardev socket,id=mon,path=/var/tmp/qemu-5298-monitor.sock
>     -mon chardev=mon,mode=control -display none -vga none'.
>     Output: 'qemu-system-aarch64: No machine specified, and there
>     is no default\nUse -machine help to list supported machines\n'.
>     Traceback (most recent call last):
>       File "<stdin>", line 1, in <module>
>       File "qemu.py", line 175, in launch
>         self._launch()
>       File "qemu.py", line 189, in _launch
>         self._post_launch()
>       File "qemu.py", line 154, in _post_launch
>         self._qmp.accept()
>       File "qmp/qmp.py", line 145, in accept
>         self.__sock, _ = self.__sock.accept()
>       File "/usr/lib64/python2.7/socket.py", line 206, in accept
>         sock, addr = self._sock.accept()
>     socket.timeout: timed out
>     >>>
>
> Signed-off-by: Amador Pahim <apahim@redhat.com>
> ---
>  scripts/qemu.py | 12 +++++++++++-
>  1 file changed, 11 insertions(+), 1 deletion(-)
>
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index e9a3a96d13..43fd0b072c 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -158,7 +158,10 @@ class QEMUMachine(object):
>              self._remove_if_exists(self._created_files.pop())
>  
>      def launch(self):
> -        '''Launch the VM and establish a QMP connection'''
> +        '''
> +        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.')
> @@ -169,6 +172,7 @@ class QEMUMachine(object):
>                                    'before launching again.')
>  
>          try:
> +            self._iolog = None
>              self._qemu_full_args = None
>              self._qemu_full_args = (self._wrapper + [self._binary] +
>                                      self._base_args() + self._args)
> @@ -176,9 +180,15 @@ class QEMUMachine(object):
>              self._pending_shutdown = True
>          except:
>              self.shutdown()
> +            LOG.debug('Error launching VM.%s%s',
> +                      ' Command: %r.' % ' '.join(self._qemu_full_args)
> +                      if self._qemu_full_args else '',
> +                      ' Output: %r.' % self._iolog
> +                      if self._iolog else '')

This nested interpolation is too ugly to live :)

Nesting is easy to avoid:

               LOG.debug('Error launching VM\n. ' Command: %r. Output: %r.'
                         % (' '.join(self._qemu_full_args)
                            if self._qemu_full_args else '',
                            self._iolog
                            if self._iolog else ''))

Why %r and not %s?

Are you sure '\n' is appropriate in the argument of LOG.debug()?

Why cram everything into a single LOG.debug()?

               LOG.debug('Error launching VM')
               LOG.debug('Command: %s' % (' '.join(self._qemu_full_args)
                                          if self._qemu_full_args else ''))
               LOG.debug('Output: %s' % self._iolog if self._iolog else ''))

>              raise
>  
>      def _launch(self):
> +        '''Launch the VM and establish a QMP connection.'''
>          self._pre_launch()
>          devnull = open(os.path.devnull, 'rb')
>          self._popen = subprocess.Popen(self._qemu_full_args,