On Wed, Jul 21, 2021 at 12:34 AM John Snow <js...@redhat.com> wrote:
>
>
> On Tue, Jul 13, 2021 at 6:07 PM G S Niteesh Babu <niteesh...@gmail.com>
> wrote:
>
>> Added a draft of AQMP TUI.
>>
>> Implements the follwing basic features:
>> 1) Command transmission/reception.
>> 2) Shows events asynchronously.
>> 3) Shows server status in the bottom status bar.
>>
>> Also added necessary pylint, mypy configurations
>>
>> Signed-off-by: G S Niteesh Babu <niteesh...@gmail.com>
>> ---
>> python/qemu/aqmp/aqmp_tui.py | 332 +++++++++++++++++++++++++++++++++++
>> python/setup.cfg | 21 ++-
>> 2 files changed, 352 insertions(+), 1 deletion(-)
>> create mode 100644 python/qemu/aqmp/aqmp_tui.py
>>
>> diff --git a/python/qemu/aqmp/aqmp_tui.py b/python/qemu/aqmp/aqmp_tui.py
>> new file mode 100644
>> index 0000000000..f853efc1f5
>> --- /dev/null
>> +++ b/python/qemu/aqmp/aqmp_tui.py
>> @@ -0,0 +1,332 @@
>> +# Copyright (c) 2021
>> +#
>> +# Authors:
>> +# Niteesh Babu G S <niteesh...@gmail.com>
>> +#
>> +# This work is licensed under the terms of the GNU GPL, version 2 or
>> +# later. See the COPYING file in the top-level directory.
>> +
>> +import argparse
>> +import asyncio
>> +import logging
>> +from logging import Handler
>> +import signal
>> +
>> +import urwid
>> +import urwid_readline
>> +
>> +from .error import MultiException
>> +from .protocol import ConnectError
>> +from .qmp_protocol import QMP, ExecInterruptedError, ExecuteError
>> +from .util import create_task, pretty_traceback
>> +
>> +
>> +UPDATE_MSG = 'UPDATE_MSG'
>> +
>> +# Using root logger to enable all loggers under qemu and asyncio
>> +LOGGER = logging.getLogger()
>> +
>> +palette = [
>> + (Token.Punctuation, '', '', '', 'h15,bold', 'g7'),
>> + (Token.Text, '', '', '', '', 'g7'),
>> + (Token.Name.Tag, '', '', '', 'bold,#f88', 'g7'),
>> + (Token.Literal.Number.Integer, '', '', '', '#fa0', 'g7'),
>> + (Token.Literal.String.Double, '', '', '', '#6f6', 'g7'),
>> + (Token.Keyword.Constant, '', '', '', '#6af', 'g7'),
>> + ('background', '', 'black', '', '', 'g7'),
>> +]
>> +
>> +
>> +class StatusBar(urwid.Text):
>> + """
>> + A simple Text widget that currently only shows connection status.
>> + """
>> + def __init__(self, text=''):
>> + super().__init__(text, align='right')
>> +
>> +
>> +class Editor(urwid_readline.ReadlineEdit):
>> + """
>> + Support urwid_readline features along with
>> + history support which lacks in urwid_readline
>> + """
>> + def __init__(self, master):
>> + super().__init__(caption='> ', multiline=True)
>> + self.master = master
>> + self.history = []
>> + self.last_index = -1
>> + self.show_history = False
>> +
>> + def keypress(self, size, key):
>> + # TODO: Add some logic for down key and clean up logic if
>> possible.
>> + # Returning None means the key has been handled by this widget
>> + # which otherwise is propogated to the parent widget to be
>> + # handled
>> + msg = self.get_edit_text()
>> + if key == 'up' and not msg:
>> + # Show the history when 'up arrow' is pressed with no input
>> text.
>> + # NOTE: The show_history logic is necessary because in
>> 'multiline'
>> + # mode (which we use) 'up arrow' is used to move between
>> lines.
>> + self.show_history = True
>> + last_msg = self.history[self.last_index] if self.history
>> else ''
>> + self.set_edit_text(last_msg)
>> + self.edit_pos = len(last_msg)
>> + self.last_index += 1
>> + elif key == 'up' and self.show_history:
>> + if self.last_index < len(self.history):
>> + self.set_edit_text(self.history[self.last_index])
>> + self.edit_pos = len(self.history[self.last_index])
>> + self.last_index += 1
>> + elif key == 'meta enter':
>> + # When using multiline, enter inserts a new line into the
>> editor
>> + # send the input to the server on alt + enter
>> + self.master.cb_send_to_server(msg)
>> + self.history.insert(0, msg)
>> + self.set_edit_text('')
>> + self.last_index = 0
>> + self.show_history = False
>> + else:
>> + self.show_history = False
>> + self.last_index = 0
>> + return super().keypress(size, key)
>> + return None
>> +
>> +
>> +class EditorWidget(urwid.Filler):
>> + """
>> + Wraps CustomEdit
>> + """
>> + def __init__(self, master):
>> + super().__init__(Editor(master), valign='top')
>> +
>> +
>> +class HistoryBox(urwid.ListBox):
>> + """
>> + Shows all the QMP message transmitted/received
>> + """
>> + def __init__(self, master):
>> + self.master = master
>> + self.history = urwid.SimpleFocusListWalker([])
>> + super().__init__(self.history)
>> +
>> + def add_to_history(self, history):
>> + self.history.append(urwid.Text(history))
>> + if self.history:
>> + self.history.set_focus(len(self.history) - 1)
>> +
>> +
>> +class HistoryWindow(urwid.Frame):
>> + """
>> + Composes the HistoryBox and EditorWidget
>> + """
>> + def __init__(self, master):
>> + self.master = master
>> + self.editor = EditorWidget(master)
>> + self.editor_widget = urwid.LineBox(self.editor)
>>
>
> It's a little confusing that "editor" is of type EditorWidget but
> "editor_widget" is urwid.LineBox.
>
Fixed.
>
>
>> + self.history = HistoryBox(master)
>> + self.body = urwid.Pile([('weight', 80, self.history),
>> + ('weight', 20, self.editor_widget)])
>> + super().__init__(self.body)
>> + urwid.connect_signal(self.master, UPDATE_MSG,
>> self.cb_add_to_history)
>> +
>> + def cb_add_to_history(self, msg, level=None):
>> + formatted = []
>> + if level:
>> + msg = f'[{level}]: {msg}'
>> + formatted.append(msg)
>> + else:
>> + lexer = lexers.JsonLexer() # pylint: disable=no-member
>> + for token in lexer.get_tokens(msg):
>> + formatted.append(token)
>> + self.history.add_to_history(formatted)
>> +
>> +
>> +class Window(urwid.Frame):
>> + """
>> + This is going to be the main window that is going to compose other
>> + windows. In this stage it is unnecesssary but will be necessary in
>> + future when we will have multiple windows and want to the switch
>> between
>> + them and display overlays
>> + """
>> + def __init__(self, master):
>> + self.master = master
>> + footer = StatusBar()
>> + body = HistoryWindow(master)
>> + super().__init__(body, footer=footer)
>> +
>> +
>> +class App(QMP):
>> + def __init__(self, address):
>> + urwid.register_signal(type(self), UPDATE_MSG)
>> + self.window = Window(self)
>> + self.address = address
>> + self.aloop = None
>> + self.loop = None
>> + super().__init__()
>> +
>> + def add_to_history(self, msg, level=None):
>> + urwid.emit_signal(self, UPDATE_MSG, msg, level)
>> +
>> + def _cb_outbound(self, msg):
>> + LOGGER.debug('Request: %s', str(msg))
>> + self.add_to_history('<-- ' + str(msg))
>> + return msg
>> +
>> + def _cb_inbound(self, msg):
>> + LOGGER.debug('Response: %s', str(msg))
>> + self.add_to_history('--> ' + str(msg))
>> + return msg
>> +
>>
>
> [DEBUG]: Response seems to duplicate the "--> {...}" incoming messages.
>
The debug stuff is nice to have because it gets saved to the logfile, but
> is there some way to omit it from the history view, even when --debug is
> on? I think we simply don't need to see the responses twice. What do you
> think?
>
Ahh, I totally missed this. I didn't really try out the TUILogHandler much.
I just made sure I was
able to log all levels of messages properly.
Yup, I too feel we should omit the inbound/outbound debug messages
during logging inside TUI.
+ async def wait_for_events(self):
>> + async for event in self.events:
>> + self.handle_event(event)
>> +
>> + async def _send_to_server(self, msg):
>> + # TODO: Handle more validation errors (eg: ValueError)
>> + try:
>> + await self._raw(bytes(msg, 'utf-8'))
>> + except ExecuteError:
>> + LOGGER.info('Error response from server for msg: %s', msg)
>> + except ExecInterruptedError:
>> + LOGGER.info('Error server disconnected before reply')
>> + # FIXME: Handle this better
>> + # Show the disconnected message in the history window
>> + urwid.emit_signal(self, UPDATE_MSG,
>> + '{"error": "Server disconnected before
>> reply"}')
>> + self.window.footer.set_text("Server disconnected")
>> + except Exception as err:
>> + LOGGER.error('Exception from _send_to_server: %s', str(err))
>> + raise err
>>
>
> Type non-JSON or a JSON value that isn't an object will crash the whole
> application.
>
> You need to look out for these:
>
> File "/home/jsnow/src/qemu/python/qemu/aqmp/qmp_protocol.py", line 479,
> in _raw
> msg = Message(msg)
> File "/home/jsnow/src/qemu/python/qemu/aqmp/message.py", line 71, in
> __init__
> self._obj = self._deserialize(self._data)
> File "/home/jsnow/src/qemu/python/qemu/aqmp/message.py", line 158, in
> _deserialize
> raise DeserializationError(emsg, data) from err
> qemu.aqmp.message.DeserializationError: Failed to deserialize QMP message.
> raw bytes were: b'q\n\n'
>
> File "/home/jsnow/src/qemu/python/qemu/aqmp/qmp_protocol.py", line 479,
> in _raw
> msg = Message(msg)
> File "/home/jsnow/src/qemu/python/qemu/aqmp/message.py", line 71, in
> __init__
> self._obj = self._deserialize(self._data)
> File "/home/jsnow/src/qemu/python/qemu/aqmp/message.py", line 160, in
> _deserialize
> raise UnexpectedTypeError(
> qemu.aqmp.message.UnexpectedTypeError: QMP message is not a JSON object.
> json value was: []
>
> There's also ValueError and TypeError, but I think the way you've written
> the shell here that there's not much of a chance to actually see these --
> they show up when serializing a python object, but you do bytes(msg) which
> means we use the *deserialization* interface to validate user input, so you
> might not actually see the other errors here ...
>
> Still, you theoretically could if somehow
> serialize(deserialize(bytes(msg)))) raised those errors. I don't expect
> that they would, but you may as well treat all of these errors the same:
> the input by the user is garbage and cannot be used. No need to exit or
> crash.
>
Will fix.
>
>
>> +
>> + def cb_send_to_server(self, msg):
>> + create_task(self._send_to_server(msg))
>> +
>> + def unhandled_input(self, key):
>> + if key == 'esc':
>> + self.kill_app()
>> +
>> + def kill_app(self):
>> + # TODO: Work on the disconnect logic
>> + create_task(self._kill_app())
>> +
>> + async def _kill_app(self):
>> + # It is ok to call disconnect even in disconnect state
>> + try:
>> + await self.disconnect()
>> + LOGGER.debug('Disconnect finished. Exiting app')
>> + except MultiException as err:
>> + LOGGER.info('Multiple exception on disconnect: %s', str(err))
>> + # Let the app crash after providing a proper stack trace
>> + raise err
>> + raise urwid.ExitMainLoop()
>>
>
> I got rid of MultiException in v2, thankfully.... !
>
Nice :).
>
> If the server goes away, aqmp-shell shows the disconnect debug messages
> well enough, but then when hitting 'esc' afterwards, we get an Exception
> printed out to the terminal. Ideally, aqmp-shell should call disconnect()
> as soon as it notices a problem and not only when we call _kill_app.
>
Will refactor.
> +
>> + def handle_event(self, event):
>> + # FIXME: Consider all states present in qapi/run-state.json
>> + if event['event'] == 'SHUTDOWN':
>> + self.window.footer.set_text('Server shutdown')
>> +
>> + async def connect_server(self):
>> + try:
>> + await self.connect(self.address)
>> + self.window.footer.set_text("Connected to {:s}".format(
>> + f"{self.address[0]}:{self.address[1]}"
>> + if isinstance(self.address, tuple)
>> + else self.address
>> + ))
>> + except ConnectError as err:
>> + LOGGER.debug('Cannot connect to server %s', str(err))
>> + self.window.footer.set_text('Server shutdown')
>> +
>> + def run(self, debug=False):
>> + self.screen.set_terminal_properties(256)
>> +
>> + self.aloop = asyncio.get_event_loop()
>> + self.aloop.set_debug(debug)
>> +
>> + # Gracefully handle SIGTERM and SIGINT signals
>> + cancel_signals = [signal.SIGTERM, signal.SIGINT]
>> + for sig in cancel_signals:
>> + self.aloop.add_signal_handler(sig, self.kill_app)
>> +
>> + event_loop = urwid.AsyncioEventLoop(loop=self.aloop)
>> + self.loop = urwid.MainLoop(self.window,
>> + unhandled_input=self.unhandled_input,
>> + handle_mouse=True,
>> + event_loop=event_loop)
>> +
>> + create_task(self.wait_for_events(), self.aloop)
>> + create_task(self.connect_server(), self.aloop)
>> + try:
>> + self.loop.run()
>> + except Exception as err:
>> + LOGGER.error('%s\n%s\n', str(err), pretty_traceback())
>> + raise err
>> +
>> +
>> +class TUILogHandler(Handler):
>> + def __init__(self, tui):
>> + super().__init__()
>> + self.tui = tui
>> +
>> + def emit(self, record):
>> + level = record.levelname
>> + msg = record.getMessage()
>> + self.tui.add_to_history(msg, level)
>> +
>> +
>> +def parse_address(address):
>> + """
>> + This snippet was taken from qemu.qmp.__init__.
>> + pylint complaints about duplicate code so it has been
>> + temprorily disabled. This should be fixed once qmp is
>> + replaced by aqmp in the future.
>> + """
>> + components = address.split(':')
>> + if len(components) == 2:
>> + try:
>> + port = int(components[1])
>> + except ValueError:
>> + raise ValueError(f'Bad Port value in {address}') from None
>> + return (components[0], port)
>> + return address
>> +
>>
>
> You can just import the old QMP package and use the old function directly.
> That will save you the trouble of needing to silence the duplicate code
> checker too.
>
OK. Will change it.
> +
>> +def main():
>> + parser = argparse.ArgumentParser(description='AQMP TUI')
>> + parser.add_argument('qmp_server', help='Address of the QMP server'
>> + '< UNIX socket path | TCP addr:port >')
>> + parser.add_argument('--log-file', help='The Log file name')
>> + parser.add_argument('--log-level', help='Log level
>> <debug|info|error>',
>> + default='debug')
>> + parser.add_argument('--debug', action='store_true',
>> + help='Enable debug mode for asyncio loop'
>> + 'Generates lot of output, makes TUI unusable
>> when'
>> + 'logs are logged in the TUI itself.'
>> + 'Use only when logging to a file')
>> + args = parser.parse_args()
>> +
>> + try:
>> + address = parse_address(args.qmp_server)
>> + except ValueError as err:
>> + parser.error(err)
>> +
>> + app = App(address)
>> +
>>
>
> Initializing the app can go down below the logging initialization stuff,
> because the init method engages the logging module to set up the loggers,
> but we want to initialize the logging paradigm ourselves before anything
> touches it.
>
I can't move it below the initialization of loggers because TUILogHandler
requires a reference to the App class.
It was the simplest way I could think of to get the log messages inside the
TUI. Any ideas on how can I refactor it?
+ if args.log_file:
>> + LOGGER.addHandler(logging.FileHandler(args.log_file))
>> + else:
>> + LOGGER.addHandler(TUILogHandler(app))
>> +
>> + log_levels = {'debug': logging.DEBUG,
>> + 'info': logging.INFO,
>> + 'error': logging.ERROR}
>>
>
> There are more log levels than just 'debug', 'info' and 'error' ...
> There's probably a way to avoid having to re-write the mapping yourself.
> Something in the logging module can help here.
>
Yes, found a way.
https://github.com/python/cpython/blob/c8e35abfe304eb052a5220974006072c37d4b06a/Lib/logging/__init__.py#L119
>
>
>> +
>> + if args.log_level not in log_levels:
>> + parser.error('Invalid log level')
>> + LOGGER.setLevel(log_levels[args.log_level])
>> +
>>
>
> You can initialize the app here instead.
>
>
>> + app.run(args.debug)
>> +
>>
>>
> I didn't pass "--debug", but I still got DEBUG messages in the history
> panel.
>
> What I'd like to see is only WARNING messages and above in the application
> unless I pass --debug, and then I want to see additional messages.
>
The --debug option is to enable the event loop logging and not the TUI
logging.
You can change the TUI logging levels using the --log-level option.
Maybe I'll rename the --debug option to --asyncio-debug and set the default
--log-level to WARNING.
> Looking good otherwise, I think it's shaping up. Thanks!
>
