diff --git a/python/qemu/aqmp/protocol.py b/python/qemu/aqmp/protocol.py index ae1df24026..5190b33b13 100644 --- a/python/qemu/aqmp/protocol.py +++ b/python/qemu/aqmp/protocol.py @@ -79,7 +79,11 @@ class ConnectError(AQMPError): self.exc: Exception = exc def __str__(self) -> str: - return f"{self.error_message}: {self.exc!s}" + cause = str(self.exc) + if not cause: + # If there's no error string, use the exception name. + cause = exception_summary(self.exc) + return f"{self.error_message}: {cause}" class StateError(AQMPError): @@ -623,13 +627,21 @@ class AsyncProtocol(Generic[T]): def _done(task: Optional['asyncio.Future[Any]']) -> bool: return task is not None and task.done() - # NB: We can't rely on _bh_tasks being done() here, it may not - # yet have had a chance to run and gather itself. + # Are we already in an error pathway? If either of the tasks are + # already done, or if we have no tasks but a reader/writer; we + # must be. + # + # NB: We can't use _bh_tasks to check for premature task + # completion, because it may not yet have had a chance to run + # and gather itself. tasks = tuple(filter(None, (self._writer_task, self._reader_task))) error_pathway = _done(self._reader_task) or _done(self._writer_task) + if not tasks: + error_pathway |= bool(self._reader) or bool(self._writer) try: - # Try to flush the writer, if possible: + # Try to flush the writer, if possible. + # This *may* cause an error and force us over into the error path. if not error_pathway: await self._bh_flush_writer() except BaseException as err: @@ -639,7 +651,7 @@ class AsyncProtocol(Generic[T]): self.logger.debug("%s:\n%s\n", emsg, pretty_traceback()) raise finally: - # Cancel any still-running tasks: + # Cancel any still-running tasks (Won't raise): if self._writer_task is not None and not self._writer_task.done(): self.logger.debug("Cancelling writer task.") self._writer_task.cancel() @@ -652,7 +664,7 @@ class AsyncProtocol(Generic[T]): self.logger.debug("Waiting for tasks to complete ...") await asyncio.wait(tasks) - # Lastly, close the stream itself. (May raise): + # Lastly, close the stream itself. (*May raise*!): await self._bh_close_stream(error_pathway) self.logger.debug("Disconnected.") diff --git a/scripts/device-crash-test b/scripts/device-crash-test index 8331c057b8..3db0ffe5b8 100755 --- a/scripts/device-crash-test +++ b/scripts/device-crash-test @@ -36,6 +36,7 @@ from itertools import chain sys.path.append(os.path.join(os.path.dirname(__file__), '..', 'python')) from qemu.machine import QEMUMachine +from qemu.aqmp import ConnectError logger = logging.getLogger('device-crash-test') dbg = logger.debug @@ -317,9 +318,7 @@ class QemuBinaryInfo(object): try: vm.launch() mi['runnable'] = True - except KeyboardInterrupt: - raise - except: + except Exception: dbg("exception trying to run binary=%s machine=%s", self.binary, machine, exc_info=sys.exc_info()) dbg("log: %r", vm.get_log()) mi['runnable'] = False @@ -357,12 +356,12 @@ def checkOneCase(args, testcase): dbg("will launch QEMU: %s", cmdline) vm = QEMUMachine(binary=binary, args=args) + exc = None exc_traceback = None try: vm.launch() - except KeyboardInterrupt: - raise - except: + except Exception as this_exc: + exc = this_exc exc_traceback = traceback.format_exc() dbg("Exception while running test case") finally: @@ -370,8 +369,9 @@ def checkOneCase(args, testcase): ec = vm.exitcode() log = vm.get_log() - if exc_traceback is not None or ec != 0: - return {'exc_traceback':exc_traceback, + if exc is not None or ec != 0: + return {'exc': exc, + 'exc_traceback':exc_traceback, 'exitcode':ec, 'log':log, 'testcase':testcase, @@ -459,6 +459,17 @@ def logFailure(f, level): for l in f['log'].strip().split('\n'): logger.log(level, "log: %s", l) logger.log(level, "exit code: %r", f['exitcode']) + + # If the Exception is merely a QMP connect error, + # reduce the logging level for its traceback to + # improve visual clarity. + if isinstance(f.get('exc'), ConnectError): + logger.log(level, "%s.%s: %s", + type(f['exc']).__module__, + type(f['exc']).__qualname__, + str(f['exc'])) + level = logging.DEBUG + if f['exc_traceback']: logger.log(level, "exception:") for l in f['exc_traceback'].split('\n'): @@ -503,6 +514,12 @@ def main(): lvl = logging.WARN logging.basicConfig(stream=sys.stdout, level=lvl, format='%(levelname)s: %(message)s') + if not args.debug: + # Async QMP, when in use, is chatty about connection failures. + # This script knowingly generates a ton of connection errors. + # Silence this logger. + logging.getLogger('qemu.aqmp.qmp_client').setLevel(logging.CRITICAL) + fatal_failures = [] wl_stats = {} skipped = 0