| |
@@ -19,11 +19,14 @@
|
| |
|
| |
"""
|
| |
|
| |
- from __future__ import absolute_import
|
| |
+ from __future__ import absolute_import, print_function
|
| |
import os
|
| |
import logging
|
| |
import logging.handlers
|
| |
import inspect
|
| |
+ import re
|
| |
+ import signal
|
| |
+ import sys
|
| |
|
| |
levels = {
|
| |
"debug": logging.DEBUG,
|
| |
@@ -203,6 +206,263 @@
|
| |
del self.handlers[build.id]
|
| |
|
| |
|
| |
+ class LocalRepo(object):
|
| |
+ def __init__(self, koji_tag):
|
| |
+ self.koji_tag = koji_tag
|
| |
+ self.current_downloads = set()
|
| |
+ self.total_downloads = 0
|
| |
+ self.completed_downloads = 0
|
| |
+ self.status = ""
|
| |
+
|
| |
+ def start_downloads(self, total):
|
| |
+ self.status = "Downloading packages"
|
| |
+ self.total_downloads = total
|
| |
+
|
| |
+ def start_download(self, url):
|
| |
+ self.current_downloads.add(url)
|
| |
+
|
| |
+ def done_download(self, url):
|
| |
+ self.current_downloads.remove(url)
|
| |
+ self.completed_downloads += 1
|
| |
+
|
| |
+ def show_status(self, stream, style):
|
| |
+ if self.total_downloads > 0:
|
| |
+ count = " {}/{}".format(self.completed_downloads, self.total_downloads)
|
| |
+ else:
|
| |
+ count = ""
|
| |
+
|
| |
+ print("{}: {}{}".format(style(self.koji_tag, bold=True), self.status, count),
|
| |
+ file=stream)
|
| |
+ for url in self.current_downloads:
|
| |
+ print(" {}".format(os.path.basename(url)), file=stream)
|
| |
+
|
| |
+
|
| |
+ # Used to split aaa\nbbbb\n to ('aaa', '\n', 'bbb', '\n')
|
| |
+ NL_DELIMITER = re.compile('(\n)')
|
| |
+ # Matches *common* ANSI control sequences
|
| |
+ # https://en.wikipedia.org/wiki/ANSI_escape_code#CSI_sequences
|
| |
+ CSI_SEQUENCE = re.compile('\033[0-9;]*[A-Za-z]')
|
| |
+
|
| |
+
|
| |
+ class EraseableStream(object):
|
| |
+ """
|
| |
+ Wrapper around a terminal stream for writing output that can be
|
| |
+ erased.
|
| |
+ """
|
| |
+
|
| |
+ def __init__(self, target):
|
| |
+ self.target = target
|
| |
+ self.lines_written = 0
|
| |
+ # We assume that the EraseableStream starts writing at column 0
|
| |
+ self.column = 0
|
| |
+ self.resize()
|
| |
+
|
| |
+ def resize(self):
|
| |
+ self.size = os.get_terminal_size(self.target.fileno())
|
| |
+
|
| |
+ def write(self, string):
|
| |
+ # We want to track how many lines we've written so that we can
|
| |
+ # back up and erase them. Tricky thing is handling wrapping.
|
| |
+
|
| |
+ # Strip control sequences
|
| |
+ plain = CSI_SEQUENCE.sub('', string)
|
| |
+
|
| |
+ for piece in NL_DELIMITER.split(plain):
|
| |
+ if piece == '\n':
|
| |
+ self.column = 0
|
| |
+ self.lines_written += 1
|
| |
+ else:
|
| |
+ self.column = self.column + len(piece)
|
| |
+ # self.column == self.size.column doesn't wrap -
|
| |
+ # normal modern terminals wrap when a character is written
|
| |
+ # that would be off-screen, not immediately when the
|
| |
+ # line is full.
|
| |
+ while self.column > self.size.columns:
|
| |
+ self.column -= self.size.columns
|
| |
+ self.lines_written += 1
|
| |
+
|
| |
+ self.target.write(string)
|
| |
+
|
| |
+ def erase(self):
|
| |
+ if self.column > 0:
|
| |
+ # move cursor to the beginning of line and delete whole line
|
| |
+ self.target.write("\033[0G\033[2K")
|
| |
+ for i in range(0, self.lines_written):
|
| |
+ # move up cursor and delete whole line
|
| |
+ self.target.write("\033[1A\033[2K")
|
| |
+
|
| |
+ self.lines_written = 0
|
| |
+ self.column = 0
|
| |
+
|
| |
+
|
| |
+ FG_COLORS = {
|
| |
+ 'green': '32',
|
| |
+ 'red': '91',
|
| |
+ }
|
| |
+
|
| |
+
|
| |
+ class MBSConsoleHandler(logging.Handler):
|
| |
+ """
|
| |
+ Special logging.Handler that is responsible for creating attractive and
|
| |
+ informative output when running a local build. To allow certain log
|
| |
+ messages to be handled differently for console output, methods in this
|
| |
+ class decorated with the @console_message decorator are propagated to
|
| |
+ the MBSLogger class.
|
| |
+
|
| |
+ When MBSLogger method is called, a normal log record is generated using
|
| |
+ the format string from the decoration. The record is logged normally
|
| |
+ in the build log or to a non-console handler, but when the event is
|
| |
+ received by this handler, the original decorated method is called instead.
|
| |
+ This method can optionally return a new string to be output to the log,
|
| |
+ or simply update internal state without logging anything.
|
| |
+
|
| |
+ This handler also implements the behavior that when the handler level
|
| |
+ is at its default INFO state, INFO level log messages are only shown if
|
| |
+ they have an extra 'console' attribute added by calling MBSLogger.console()
|
| |
+ rather than MBSLogger.info(). This allow further trimming down the
|
| |
+ set of messages logged to the console without losing the distinction between
|
| |
+ DEBUG and INFO.
|
| |
+ """
|
| |
+ console_messages = {}
|
| |
+
|
| |
+ def __init__(self, *args, stream=sys.stderr, **kwargs):
|
| |
+ self.stream = stream
|
| |
+
|
| |
+ self.tty = self.stream.isatty()
|
| |
+ if self.tty:
|
| |
+ self.status_stream = EraseableStream(self.stream)
|
| |
+ else:
|
| |
+ self.status_stream = None
|
| |
+
|
| |
+ self.long_running = None
|
| |
+ self.repos = {}
|
| |
+
|
| |
+ self.debug_formatter = logging.Formatter(log_format)
|
| |
+ self.info_formatter = logging.Formatter("%(message)s")
|
| |
+ self.error_formatter = logging.Formatter(
|
| |
+ self.style("%(levelname)s", bold=True, fg='red') + " - %(message)s")
|
| |
+
|
| |
+ logging.Handler.__init__(self, *args, level=logging.INFO, **kwargs)
|
| |
+
|
| |
+ def style(self, text, bold=False, fg=None):
|
| |
+ if self.tty:
|
| |
+ start = ""
|
| |
+ if bold:
|
| |
+ start += "\033[1m"
|
| |
+ if fg:
|
| |
+ start += "\033[" + FG_COLORS[fg] + "m"
|
| |
+ return start + text + "\033[0m"
|
| |
+ else:
|
| |
+ return text
|
| |
+
|
| |
+ def emit(self, record):
|
| |
+ if self.level == logging.INFO and record.levelno == logging.INFO:
|
| |
+ if not getattr(record, 'console', False):
|
| |
+ return
|
| |
+
|
| |
+ self.acquire()
|
| |
+ try:
|
| |
+ if self.tty:
|
| |
+ self.status_stream.erase()
|
| |
+
|
| |
+ console_message_callback = self.console_messages.get(record.msg)
|
| |
+ if console_message_callback:
|
| |
+ formatted = console_message_callback(self, *record.args)
|
| |
+ else:
|
| |
+ if self.level < logging.INFO:
|
| |
+ formatted = self.debug_formatter.format(record)
|
| |
+ elif record.levelno == logging.INFO:
|
| |
+ formatted = self.info_formatter.format(record)
|
| |
+ else:
|
| |
+ formatted = self.error_formatter.format(record)
|
| |
+
|
| |
+ if formatted:
|
| |
+ if self.long_running:
|
| |
+ print(file=self.stream)
|
| |
+ self.long_running = None
|
| |
+
|
| |
+ print(formatted, file=self.stream)
|
| |
+
|
| |
+ if self.tty:
|
| |
+ if self.repos:
|
| |
+ print('------------------------------', file=self.status_stream)
|
| |
+ for repo in self.repos.values():
|
| |
+ repo.show_status(self.status_stream, self.style)
|
| |
+ finally:
|
| |
+ self.release()
|
| |
+
|
| |
+ def console_message(msg):
|
| |
+ def decorate(f):
|
| |
+ f.console_message = msg
|
| |
+ return f
|
| |
+
|
| |
+ return decorate
|
| |
+
|
| |
+ def resize(self):
|
| |
+ if self.status_stream:
|
| |
+ self.status_stream.resize()
|
| |
+
|
| |
+ @console_message("%s ...")
|
| |
+ def long_running_start(self, msg):
|
| |
+ if self.long_running:
|
| |
+ print("", file=self.stream)
|
| |
+ self.long_running = msg
|
| |
+ print("{} ...".format(msg),
|
| |
+ file=self.stream, end="")
|
| |
+ self.stream.flush()
|
| |
+
|
| |
+ @console_message("%s ... done")
|
| |
+ def long_running_end(self, msg):
|
| |
+ if self.long_running == msg:
|
| |
+ self.long_running = None
|
| |
+ print(" done",
|
| |
+ file=self.stream)
|
| |
+ else:
|
| |
+ self.long_running = None
|
| |
+ return "{} ... done".format(msg)
|
| |
+
|
| |
+ @console_message("%s: Making local repository for Koji tag")
|
| |
+ def local_repo_start(self, koji_tag):
|
| |
+ repo = LocalRepo(koji_tag)
|
| |
+ self.repos[koji_tag] = repo
|
| |
+
|
| |
+ return "{}: Making local repository for Koji tag".format(
|
| |
+ self.style(koji_tag, bold=True))
|
| |
+
|
| |
+ @console_message("%s: %s")
|
| |
+ def local_repo_done(self, koji_tag, message):
|
| |
+ del self.repos[koji_tag]
|
| |
+
|
| |
+ return "{}: {}".format(
|
| |
+ self.style(koji_tag, bold=True),
|
| |
+ self.style(message, fg='green', bold=True))
|
| |
+
|
| |
+ @console_message("%s: Downloading %d packages from Koji tag to %s")
|
| |
+ def local_repo_start_downloads(self, koji_tag, num_packages, repo_dir):
|
| |
+ repo = self.repos[koji_tag]
|
| |
+ repo.start_downloads(num_packages)
|
| |
+
|
| |
+ @console_message("%s: Downloading %s")
|
| |
+ def local_repo_start_download(self, koji_tag, url):
|
| |
+ repo = self.repos[koji_tag]
|
| |
+ repo.start_download(url)
|
| |
+
|
| |
+ @console_message("%s: Done downloading %s")
|
| |
+ def local_repo_done_download(self, koji_tag, url):
|
| |
+ repo = self.repos[koji_tag]
|
| |
+ repo.done_download(url)
|
| |
+
|
| |
+ @classmethod
|
| |
+ def _setup_console_messages(cls):
|
| |
+ for value in cls.__dict__.values():
|
| |
+ console_message = getattr(value, 'console_message', None)
|
| |
+ if console_message:
|
| |
+ cls.console_messages[console_message] = value
|
| |
+
|
| |
+
|
| |
+ MBSConsoleHandler._setup_console_messages()
|
| |
+
|
| |
+
|
| |
class MBSLogger:
|
| |
def __init__(self):
|
| |
self._logger = logging.getLogger("MBS")
|
| |
@@ -231,6 +491,9 @@
|
| |
def info(self, *args, **kwargs):
|
| |
return self._log_call("info", args, kwargs)
|
| |
|
| |
+ def console(self, *args, **kwargs):
|
| |
+ return self._log_call("info", args, kwargs, console=True)
|
| |
+
|
| |
def warning(self, *args, **kwargs):
|
| |
return self._log_call("warning", args, kwargs)
|
| |
|
| |
@@ -246,15 +509,38 @@
|
| |
def log(self, *args, **kwargs):
|
| |
return self._log_call("log", args, kwargs)
|
| |
|
| |
- def _log_call(self, level_name, args, kwargs):
|
| |
+ def _log_call(self, level_name, args, kwargs, console=False):
|
| |
caller_filename = inspect.stack()[2][1]
|
| |
caller_filename = os.path.normpath(caller_filename)
|
| |
if not caller_filename.startswith(self._current_path):
|
| |
log_name = "MBS"
|
| |
else:
|
| |
log_name = "MBS" + caller_filename[len(self._current_path):-3].replace("/", ".")
|
| |
+
|
| |
+ if console:
|
| |
+ kwargs.setdefault('extra', {})['console'] = True
|
| |
+
|
| |
return getattr(logging.getLogger(log_name), level_name)(*args, **kwargs)
|
| |
|
| |
+ # @console_message decorated methods of MBSConsoleHandler are also propagated
|
| |
+ # as additional methods of this class
|
| |
+
|
| |
+ @classmethod
|
| |
+ def _setup_console_message(cls, msg, callback):
|
| |
+ def log_method(self, *args):
|
| |
+ self.console(msg, *args)
|
| |
+
|
| |
+ log_method.__name__ = callback.__name__
|
| |
+ setattr(cls, callback.__name__, log_method)
|
| |
+
|
| |
+ @classmethod
|
| |
+ def _setup_console_messages(cls):
|
| |
+ for msg, callback in MBSConsoleHandler.console_messages.items():
|
| |
+ cls._setup_console_message(msg, callback)
|
| |
+
|
| |
+
|
| |
+ MBSLogger._setup_console_messages()
|
| |
+
|
| |
|
| |
def str_to_log_level(level):
|
| |
"""
|
| |
@@ -280,7 +566,19 @@
|
| |
log_backend = conf.log_backend
|
| |
|
| |
if not log_backend or len(log_backend) == 0 or log_backend == "console":
|
| |
- logging.basicConfig(level=conf.log_level, format=log_format)
|
| |
+ if conf.system == "mock":
|
| |
+ root_logger = logging.getLogger()
|
| |
+ root_logger.setLevel(conf.log_level)
|
| |
+ handler = MBSConsoleHandler()
|
| |
+ root_logger.addHandler(handler)
|
| |
+
|
| |
+ def handle_sigwinch(*args):
|
| |
+ handler.resize()
|
| |
+
|
| |
+ signal.signal(signal.SIGWINCH, handle_sigwinch)
|
| |
+ else:
|
| |
+ logging.basicConfig(level=conf.log_level, format=log_format)
|
| |
+
|
| |
log = MBSLogger()
|
| |
log.level = conf.log_level
|
| |
else:
|
| |
otaylor
commented a year ago
When running in local mode, add a special handler that filters log messages to the console to produce attractive output. Implemented behaviors include:
Long running operations can be displayed to the console as"Doing foo ... <pause>done"
A second patch adds dynamic display of downloads on top of this: when downloading files from Koji to make a local repository, display a temporary status of which files are being displayed to the console appended after any log messages. Updates are done by erasing the status that was written, adding a log message, then writing the status again.