Re: [PULL 10/41] python/qemu: Add ConsoleSocket for optional use in QEMUMachine

[John Snow <jsnow@redhat.com>]

On 7/7/20 3:08 AM, Alex Bennée wrote:
> From: Robert Foley <robert.foley@linaro.org>
> 

Hi, this creates some pylint regressions, can they please be addressed
first?

> We add the ConsoleSocket object, which has a socket interface
> and which will consume all arriving characters on the
> socket, placing them into an in memory buffer.
> This will also provide those chars via recv() as
> would a regular socket.
> ConsoleSocket also has the option of dumping
> the console bytes to a log file.
> 
> We also give QEMUMachine the option of using ConsoleSocket
> to drain and to use for logging console to a file.
> By default QEMUMachine does not use ConsoleSocket.
> 
> This is added in preparation for use by basevm.py in a later commit.
> This is a workaround we found was needed for basevm.py since
> there is a known issue where QEMU will hang waiting
> for console characters to be consumed.
> 
> Cc: Eduardo Habkost <ehabkost@redhat.com>
> Cc: Cleber Rosa <crosa@redhat.com>
> Signed-off-by: Robert Foley <robert.foley@linaro.org>
> Reviewed-by: Peter Puhov <peter.puhov@linaro.org>
> Acked-by: Alex Bennée <alex.bennee@linaro.org>
> Tested-by: Philippe Mathieu-Daudé <philmd@redhat.com>
> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
> Message-Id: <20200601211421.1277-9-robert.foley@linaro.org>
> Message-Id: <20200701135652.1366-13-alex.bennee@linaro.org>
> 
> diff --git a/python/qemu/console_socket.py b/python/qemu/console_socket.py
> new file mode 100644
> index 000000000000..830cb7c62825
> --- /dev/null
> +++ b/python/qemu/console_socket.py
> @@ -0,0 +1,110 @@
> +#!/usr/bin/env python3

> +#
> +# This python module implements a ConsoleSocket object which is
> +# designed always drain the socket itself, and place
> +# the bytes into a in memory buffer for later processing.
> +#
> +# Optionally a file path can be passed in and we will also
> +# dump the characters to this file for debug.
> +#

Convert to a module docstring, please.

> +# Copyright 2020 Linaro
> +#
> +# Authors:
> +#  Robert Foley <robert.foley@linaro.org>
> +#
> +# This code is licensed under the GPL version 2 or later.  See
> +# the COPYING file in the top-level directory.
> +#
> +import asyncore
> +import socket
> +import threading

vvv

> +import io
> +import os
> +import sys

^^^ unused, remove

> +from collections import deque
> +import time
> +import traceback
> +

Add one more blank line here, for flake8.

> +class ConsoleSocket(asyncore.dispatcher):
> +
> +    def __init__(self, address, file=None):
> +        self._recv_timeout_sec = 300
> +        self._buffer = deque()
> +        self._asyncore_thread = None
> +        self._sock = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
> +        self._sock.connect(address)
> +        self._logfile = None
> +        if file:
> +            self._logfile = open(file, "w")
> +        asyncore.dispatcher.__init__(self, sock=self._sock)
> +        self._open = True
> +        self._thread_start()
> +
> +    def _thread_start(self):
> +        """Kick off a thread to wait on the asyncore.loop"""
> +        if self._asyncore_thread is not None:
> +            return
> +        self._asyncore_thread = threading.Thread(target=asyncore.loop,
> +                                                 kwargs={'timeout':1})

Add a space after the colon here.

> +        self._asyncore_thread.daemon = True
> +        self._asyncore_thread.start()
> +
> +    def handle_close(self):
> +        """redirect close to base class"""
> +        # Call the base class close, but not self.close() since
> +        # handle_close() occurs in the context of the thread which
> +        # self.close() attempts to join.
> +        asyncore.dispatcher.close(self)
> +
> +    def close(self):
> +        """Close the base object and wait for the thread to terminate"""
> +        if self._open:
> +            self._open = False
> +            asyncore.dispatcher.close(self)
> +            if self._asyncore_thread is not None:
> +                thread, self._asyncore_thread = self._asyncore_thread, None
> +                thread.join()
> +            if self._logfile:
> +                self._logfile.close()
> +                self._logfile = None
> +
> +    def handle_read(self):
> +        """process arriving characters into in memory _buffer"""
> +        try:
> +            data = asyncore.dispatcher.recv(self, 1)
> +            # latin1 is needed since there are some chars
> +            # we are receiving that cannot be encoded to utf-8
> +            # such as 0xe2, 0x80, 0xA6.
> +            string = data.decode("latin1")
> +        except:
> +            print("Exception seen.")
> +            traceback.print_exc()
> +            return

Please, no bare exceptions unless you re-raise the error.
If you want to handle the error, please handle the error in the caller
and not the shared library code.

As it is, I have no idea what errors you saw that might have warranted
this exclusion.

> +        if self._logfile:
> +            self._logfile.write("{}".format(string))
> +            self._logfile.flush()
> +        for c in string:
> +            self._buffer.extend(c)
> +

Pylint complains about the usage of 'c' here, but that's okay. Please
amend pylintrc to allow this usage by amending the "good-names" section.

> +    def recv(self, n=1, sleep_delay_s=0.1):
> +        """Return chars from in memory buffer"""
> +        start_time = time.time()
> +        while len(self._buffer) < n:
> +            time.sleep(sleep_delay_s)
> +            elapsed_sec = time.time() - start_time
> +            if elapsed_sec > self._recv_timeout_sec:
> +                raise socket.timeout
> +        chars = ''.join([self._buffer.popleft() for i in range(n)])
> +        # We choose to use latin1 to remain consistent with
> +        # handle_read() and give back the same data as the user would
> +        # receive if they were reading directly from the
> +        # socket w/o our intervention.
> +        return chars.encode("latin1")
> +

console_socket.py:89:4: W0221: Parameters differ from overridden 'recv'
method (arguments-differ)

Seems pretty different from the asyncore.dispatcher recv method, is that
intentional?

https://github.com/python/cpython/blob/master/Lib/asyncore.py

Does overriding this way break any other methods that we expect to work?

> +    def set_blocking(self):
> +        """Maintain compatibility with socket API"""
> +        pass
> +

You can remove the pass statement here because the docstring fulfills
the role of providing a function body.

> +    def settimeout(self, seconds):
> +        """Set current timeout on recv"""
> +        self._recv_timeout_sec = seconds
> diff --git a/python/qemu/machine.py b/python/qemu/machine.py
> index 041c615052e4..c25f0b42cf60 100644
> --- a/python/qemu/machine.py
> +++ b/python/qemu/machine.py
> @@ -26,6 +26,7 @@ import socket
>  import tempfile
>  from typing import Optional, Type
>  from types import TracebackType
> +from qemu.console_socket import ConsoleSocket
>  

Match the import style for other relative imports in the module, as below.

>  from . import qmp
>  
> @@ -75,7 +76,8 @@ class QEMUMachine:
>  
>      def __init__(self, binary, args=None, wrapper=None, name=None,
>                   test_dir="/var/tmp", monitor_address=None,
> -                 socket_scm_helper=None, sock_dir=None):
> +                 socket_scm_helper=None, sock_dir=None,
> +                 drain_console=False, console_log=None):
>          '''
>          Initialize a QEMUMachine
>  
> @@ -86,6 +88,9 @@ class QEMUMachine:
>          @param test_dir: where to create socket and log file
>          @param monitor_address: address for QMP monitor
>          @param socket_scm_helper: helper program, required for send_fd_scm()
> +        @param sock_dir: where to create socket (overrides test_dir for sock)
> +        @param console_log: (optional) path to console log file
> +        @param drain_console: (optional) True to drain console socket to buffer
>          @note: Qemu process is not started until launch() is used.
>          '''
>          if args is None:
> @@ -122,6 +127,12 @@ class QEMUMachine:
>          self._console_address = None
>          self._console_socket = None
>          self._remove_files = []
> +        self._console_log_path = console_log
> +        if self._console_log_path:
> +            # In order to log the console, buffering needs to be enabled.
> +            self._drain_console = True
> +        else:
> +            self._drain_console = drain_console
>  
>      def __enter__(self):
>          return self
> @@ -580,7 +591,11 @@ class QEMUMachine:
>          Returns a socket connected to the console
>          """
>          if self._console_socket is None:
> -            self._console_socket = socket.socket(socket.AF_UNIX,
> -                                                 socket.SOCK_STREAM)
> -            self._console_socket.connect(self._console_address)
> +            if self._drain_console:
> +                self._console_socket = ConsoleSocket(self._console_address,
> +                                                    file=self._console_log_path)

Needs one more space, but the line is already too long as-is.

> +            else:
> +                self._console_socket = socket.socket(socket.AF_UNIX,
> +                                                     socket.SOCK_STREAM)
> +                self._console_socket.connect(self._console_address)
>          return self._console_socket
> 

This makes the typing for _console_socket really tough ... but
technically not a regression as the mypy code isn't merged yet.

--js