| Message ID | 20200519132259.405-13-robert.foley@linaro.org (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | tests/vm: Add support for aarch64 VMs | expand |
Robert Foley <robert.foley@linaro.org> writes: I think you need to look at adding: [sendemail] cccmd = scripts/get_maintainer.pl --nogit-fallback to your .git/config to ensure maintainers get pinged when you touch their subsystems. Eduardo and Cleber CC'd > The ConsoleSocket object provides a socket interface > which will consume all arriving characters on the > socket, but will provide those chars via recv() as > would a regular socket. > This is a workaround we found was needed since > there is a known issue where QEMU will hang waiting > for console characters to be consumed. > We also add the option of logging the console to a file. > > Signed-off-by: Robert Foley <robert.foley@linaro.org> > Reviewed-by: Peter Puhov <peter.puhov@linaro.org> > --- > python/qemu/console_socket.py | 162 ++++++++++++++++++++++++++++++++++ > python/qemu/machine.py | 23 ++++- > tests/vm/Makefile.include | 4 + > tests/vm/basevm.py | 19 +++- > 4 files changed, 202 insertions(+), 6 deletions(-) > create mode 100644 python/qemu/console_socket.py > > diff --git a/python/qemu/console_socket.py b/python/qemu/console_socket.py > new file mode 100644 > index 0000000000..a1f74e60ac > --- /dev/null > +++ b/python/qemu/console_socket.py > @@ -0,0 +1,162 @@ > +#!/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. > +# > +# 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 > +import io > +import os > +import sys > +from collections import deque > +import time > +import traceback Left over debug? > + > +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._thread_start() > + self._open = True > + > + 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}) > + 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 > + if self._logfile: > + self._logfile.write("{}".format(string)) > + self._logfile.flush() > + for c in string: > + self._buffer.append(c) > + > + def recv(self, n=1): > + """Return chars from in memory buffer""" > + start_time = time.time() > + while len(self._buffer) < n: > + time.sleep(0.1) > + 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") > + > + def set_blocking(self): > + """Maintain compatibility with socket API""" > + pass > + > + def settimeout(self, seconds): > + """Set current timeout on recv""" > + self._recv_timeout_sec = seconds > + > +class ByteBuffer(deque): > + """Simple in memory buffer with read/write interface""" > + def write(self, bytes): > + for i in bytes: > + self.append(i) > + def read(self, n): > + return ''.join([self.popleft() for i in range(n)]) > + > +if __name__ == '__main__': If the module is meant to be executable then you need to +x the file. However since 8f8fd9edba I think everything is meant to be doing things the pythonic way as a proper module. I'm not sure where unit tests for the modules are meant to sit in this case. > + # Brief test to exercise the above code. > + # The ConsoleSocket will ship some data to the server, > + # the server will echo it back and the client will echo what it received. > + > + # First remove the socket. > + address = "./test_console_socket" > + if os.path.exists(address): > + os.unlink(address) > + > + # Create the server side. > + server_socket = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) > + server_socket.bind(address) > + server_socket.listen(1) > + > + # Create the object we are trying to test. > + console_socket = ConsoleSocket(address, file="./logfile.txt") > + > + # Generate some data and ship it over the socket. > + send_data = "" > + for i in range(10): > + send_data += "this is a test message {}\n".format(i) > + console_socket.send(send_data.encode('latin1')) > + connection, client_address = server_socket.accept() > + > + # Process the data on the server and ship it back. > + data = connection.recv(len(send_data)) > + print("server received: {}".format(data)) > + print("server: sending data back to the client") > + connection.sendall(data) > + > + # Client receives teh bytes and displays them. s/teh/the/ > + print("client: receiving bytes") > + bytes = console_socket.recv(len(data)) > + recv_data = bytes.decode('latin1') > + print("client received: {}".format(recv_data)) > + assert(recv_data == send_data) > + # Close console connection first, then close server. > + console_socket.close() > + connection.close() > + server_socket.close() > + print("test successful.") > + I think in this case it might be worth splitting introducing the functionally into the python library from the actual usage of it in the wider machines. Otherwise it seems to work well enough for me. I'd like the proper python gurus to have a look over it though. Acked-by: Alex Bennée <alex.bennee@linaro.org>
On Fri, 22 May 2020 at 12:31, Alex Bennée <alex.bennee@linaro.org> wrote: > > > Robert Foley <robert.foley@linaro.org> writes: > > I think you need to look at adding: > > [sendemail] > cccmd = scripts/get_maintainer.pl --nogit-fallback > > to your .git/config to ensure maintainers get pinged when you touch > their subsystems. Eduardo and Cleber CC'd Thanks for pointing this out! We will definitely add it and use it. > > The ConsoleSocket object provides a socket interface > > which will consume all arriving characters on the > > socket, but will provide those chars via recv() as > > would a regular socket. > > This is a workaround we found was needed since > > there is a known issue where QEMU will hang waiting > > for console characters to be consumed. > > We also add the option of logging the console to a file. > > > > Signed-off-by: Robert Foley <robert.foley@linaro.org> > > Reviewed-by: Peter Puhov <peter.puhov@linaro.org> > > --- > > python/qemu/console_socket.py | 162 ++++++++++++++++++++++++++++++++++ > > python/qemu/machine.py | 23 ++++- > > tests/vm/Makefile.include | 4 + > > tests/vm/basevm.py | 19 +++- > > 4 files changed, 202 insertions(+), 6 deletions(-) > > create mode 100644 python/qemu/console_socket.py > > > > diff --git a/python/qemu/console_socket.py b/python/qemu/console_socket.py <snip> > > +import traceback > > Left over debug? This is getting used here in a try except in handle_read, to display the exception information. <snip> > > + 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 > > + if self._logfile: > > + self._logfile.write("{}".format(string)) > > + self._logfile.flush() > > + for c in string: > > + self._buffer.append(c) <snip> > > +if __name__ == '__main__': > > If the module is meant to be executable then you need to +x the file. > However since 8f8fd9edba I think everything is meant to be doing things > the pythonic way as a proper module. I'm not sure where unit tests for > the modules are meant to sit in this case. That is a good point. I see the other modules at this level do not have tests like this, so I am going to remove this for now, as I think it adds limited value at this point. > > > + # Brief test to exercise the above code. > > + # The ConsoleSocket will ship some data to the server, > > + # the server will echo it back and the client will echo what it received. > > + > > + # First remove the socket. > > + address = "./test_console_socket" > > + if os.path.exists(address): > > + os.unlink(address) > > + > > + # Create the server side. > > + server_socket = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) > > + server_socket.bind(address) > > + server_socket.listen(1) > > + > > + # Create the object we are trying to test. > > + console_socket = ConsoleSocket(address, file="./logfile.txt") > > + > > + # Generate some data and ship it over the socket. > > + send_data = "" > > + for i in range(10): > > + send_data += "this is a test message {}\n".format(i) > > + console_socket.send(send_data.encode('latin1')) > > + connection, client_address = server_socket.accept() > > + > > + # Process the data on the server and ship it back. > > + data = connection.recv(len(send_data)) > > + print("server received: {}".format(data)) > > + print("server: sending data back to the client") > > + connection.sendall(data) > > + > > + # Client receives teh bytes and displays them. > > s/teh/the/ > > > + print("client: receiving bytes") > > + bytes = console_socket.recv(len(data)) > > + recv_data = bytes.decode('latin1') > > + print("client received: {}".format(recv_data)) > > + assert(recv_data == send_data) > > + # Close console connection first, then close server. > > + console_socket.close() > > + connection.close() > > + server_socket.close() > > + print("test successful.") > > + > > I think in this case it might be worth splitting introducing the > functionally into the python library from the actual usage of it in the > wider machines. OK, I'll split this out into a separate patch. Thanks & Regards, -Rob > > Otherwise it seems to work well enough for me. I'd like the proper > python gurus to have a look over it though. > > Acked-by: Alex Bennée <alex.bennee@linaro.org> > > -- > Alex Bennée
diff --git a/python/qemu/console_socket.py b/python/qemu/console_socket.py new file mode 100644 index 0000000000..a1f74e60ac --- /dev/null +++ b/python/qemu/console_socket.py @@ -0,0 +1,162 @@ +#!/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. +# +# 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 +import io +import os +import sys +from collections import deque +import time +import traceback + +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._thread_start() + self._open = True + + 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}) + 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 + if self._logfile: + self._logfile.write("{}".format(string)) + self._logfile.flush() + for c in string: + self._buffer.append(c) + + def recv(self, n=1): + """Return chars from in memory buffer""" + start_time = time.time() + while len(self._buffer) < n: + time.sleep(0.1) + 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") + + def set_blocking(self): + """Maintain compatibility with socket API""" + pass + + def settimeout(self, seconds): + """Set current timeout on recv""" + self._recv_timeout_sec = seconds + +class ByteBuffer(deque): + """Simple in memory buffer with read/write interface""" + def write(self, bytes): + for i in bytes: + self.append(i) + def read(self, n): + return ''.join([self.popleft() for i in range(n)]) + +if __name__ == '__main__': + # Brief test to exercise the above code. + # The ConsoleSocket will ship some data to the server, + # the server will echo it back and the client will echo what it received. + + # First remove the socket. + address = "./test_console_socket" + if os.path.exists(address): + os.unlink(address) + + # Create the server side. + server_socket = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) + server_socket.bind(address) + server_socket.listen(1) + + # Create the object we are trying to test. + console_socket = ConsoleSocket(address, file="./logfile.txt") + + # Generate some data and ship it over the socket. + send_data = "" + for i in range(10): + send_data += "this is a test message {}\n".format(i) + console_socket.send(send_data.encode('latin1')) + connection, client_address = server_socket.accept() + + # Process the data on the server and ship it back. + data = connection.recv(len(send_data)) + print("server received: {}".format(data)) + print("server: sending data back to the client") + connection.sendall(data) + + # Client receives teh bytes and displays them. + print("client: receiving bytes") + bytes = console_socket.recv(len(data)) + recv_data = bytes.decode('latin1') + print("client received: {}".format(recv_data)) + assert(recv_data == send_data) + # Close console connection first, then close server. + console_socket.close() + connection.close() + server_socket.close() + print("test successful.") + diff --git a/python/qemu/machine.py b/python/qemu/machine.py index b9a98e2c86..30e7a16b92 100644 --- a/python/qemu/machine.py +++ b/python/qemu/machine.py @@ -24,6 +24,7 @@ import subprocess import shutil import socket import tempfile +from qemu.console_socket import ConsoleSocket from . import qmp @@ -71,7 +72,8 @@ class QEMUMachine(object): 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 @@ -82,6 +84,9 @@ class QEMUMachine(object): @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: @@ -118,6 +123,12 @@ class QEMUMachine(object): 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 # just in case logging wasn't configured by the main script: logging.basicConfig() @@ -568,7 +579,11 @@ class QEMUMachine(object): 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) + else: + self._console_socket = socket.socket(socket.AF_UNIX, + socket.SOCK_STREAM) + self._console_socket.connect(self._console_address) return self._console_socket diff --git a/tests/vm/Makefile.include b/tests/vm/Makefile.include index f13f0b5495..a1aa1adf3d 100644 --- a/tests/vm/Makefile.include +++ b/tests/vm/Makefile.include @@ -49,6 +49,7 @@ endif @echo ' EXTRA_CONFIGURE_OPTS="..."' @echo " J=[0..9]* - Override the -jN parameter for make commands" @echo " DEBUG=1 - Enable verbose output on host and interactive debugging" + @echo " LOG_CONSOLE=1 - Log console to file in: ~/.cache/qemu-vm " @echo " V=1 - Enable verbose ouput on host and guest commands" @echo " QEMU_LOCAL=1 - Use QEMU binary local to this build." @echo " QEMU=/path/to/qemu - Change path to QEMU binary" @@ -74,6 +75,7 @@ $(IMAGES_DIR)/%.img: $(SRC_PATH)/tests/vm/% \ $(if $(V)$(DEBUG), --debug) \ $(if $(GENISOIMAGE),--genisoimage $(GENISOIMAGE)) \ $(if $(EFI_AARCH64),--efi-aarch64 $(EFI_AARCH64)) \ + $(if $(LOG_CONSOLE),--log-console) \ --build-path $(BUILD_DIR)\ --image "$@" \ --force \ @@ -90,6 +92,7 @@ vm-build-%: $(IMAGES_DIR)/%.img $(if $(J),--jobs $(J)) \ $(if $(V),--verbose) \ $(if $(EFI_AARCH64),--efi-aarch64 $(EFI_AARCH64)) \ + $(if $(LOG_CONSOLE),--log-console) \ --build-path $(BUILD_DIR)\ --image "$<" \ $(if $(BUILD_TARGET),--build-target $(BUILD_TARGET)) \ @@ -113,6 +116,7 @@ vm-boot-ssh-%: $(IMAGES_DIR)/%.img $(if $(J),--jobs $(J)) \ $(if $(V)$(DEBUG), --debug) \ $(if $(EFI_AARCH64),--efi-aarch64 $(EFI_AARCH64)) \ + $(if $(LOG_CONSOLE),--log-console) \ --build-path $(BUILD_DIR)\ --image "$<" \ --interactive \ diff --git a/tests/vm/basevm.py b/tests/vm/basevm.py index 3b63076e25..af7b330fdf 100644 --- a/tests/vm/basevm.py +++ b/tests/vm/basevm.py @@ -82,6 +82,8 @@ class BaseVM(object): poweroff = "poweroff" # enable IPv6 networking ipv6 = True + # This is the timeout on the wait for console bytes. + socket_timeout = 120 # Scale up some timeouts under TCG. # 4 is arbitrary, but greater than 2, # since we found we need to wait more than twice as long. @@ -115,6 +117,11 @@ class BaseVM(object): "w").write(self._config['ssh_pub_key']) self.debug = args.debug + self._console_log_path = None + if args.log_console: + self._console_log_path = \ + os.path.join(os.path.expanduser("~/.cache/qemu-vm"), + "{}.install.log".format(self.name)) self._stderr = sys.stderr self._devnull = open(os.devnull, "w") if self.debug: @@ -269,7 +276,9 @@ class BaseVM(object): args += self._data_args + extra_args + self._config['extra_args'] logging.debug("QEMU args: %s", " ".join(args)) qemu_path = get_qemu_path(self.arch, self._build_path) - guest = QEMUMachine(binary=qemu_path, args=args) + guest = QEMUMachine(binary=qemu_path, args=args, + console_log=self._console_log_path, + drain_console=True) guest.set_machine(self._config['machine']) guest.set_console() try: @@ -283,6 +292,8 @@ class BaseVM(object): raise atexit.register(self.shutdown) self._guest = guest + # Init console so we can start consuming the chars. + self.console_init() usernet_info = guest.qmp("human-monitor-command", command_line="info usernet") self.ssh_port = None @@ -294,7 +305,9 @@ class BaseVM(object): raise Exception("Cannot find ssh port from 'info usernet':\n%s" % \ usernet_info) - def console_init(self, timeout = 120): + def console_init(self, timeout = None): + if timeout == None: + timeout = self.socket_timeout vm = self._guest vm.console_socket.settimeout(timeout) self.console_raw_path = os.path.join(vm._temp_dir, @@ -578,6 +591,8 @@ def parse_args(vmcls): parser.add_option("--efi-aarch64", default="/usr/share/qemu-efi-aarch64/QEMU_EFI.fd", help="Path to efi image for aarch64 VMs.") + parser.add_option("--log-console", action="store_true", + help="Log console to file.") parser.disable_interspersed_args() return parser.parse_args()