On Fri, 9 Oct 2015 01:57:27 -0400
Mike Frysinger <[email protected]> wrote:
> This has everything you could ever want:
> - control where output is sent (stdout or a file)
> - control over log level
> - automatic exit when CRITICAL is used
> - automatic colorization of critical/error/warning messages
> - explicit control over use of colors
> - automatic handling of embedded newlines
> - standardized output format
> - all logging routed through a single logger (not the root)
> - additional log level between warning & info: notice
>
> This just lays the groundwork -- no code is actually converted over
> to using this. That will be done in follow up commit(s).
>
> Note: The default output level has changed from "info" to "notice".
> That means the default display won't spam w/irrelevant details.
>
> Example output (only the main.py module is converted):
> $ ./bin/wrapper.py -s test
> 09 Oct 2015 01:34:56 EDT: NOTICE : Using default Catalyst
> configuration file: /etc/catalyst/catalyst.conf ContentsMap:
> __init__(), search_order = ['pixz', 'lbzip2', 'isoinfo_l',
> 'squashfs', 'gzip', 'xz', 'bzip2', 'tar', 'isoinfo_f'] Creating
> Portage tree snapshot test from /usr/portage... ^C
>
> $ ./bin/wrapper.py -s test --debug
> 09 Oct 2015 01:35:43 EDT: INFO : main.py:version: Catalyst git
> 09 Oct 2015 01:35:43 EDT: INFO : main.py:version: vcs version
> 4440e8908c677d8764e29b0f127e2dd6c02b7621, date Fri Oct 9 01:28:19
> 2015 -0400 09 Oct 2015 01:35:43 EDT: INFO : main.py:version:
> Copyright 2003-2015 Gentoo Foundation 09 Oct 2015 01:35:43 EDT:
> INFO : main.py:version: Copyright 2008-2012 various authors 09 Oct
> 2015 01:35:43 EDT: INFO : main.py:version: Distributed under the
> GNU General Public License version 2.1 09 Oct 2015 01:35:43 EDT:
> NOTICE : log.py:notice: Using default Catalyst configuration
> file: /etc/catalyst/catalyst.conf 09 Oct 2015 01:35:43 EDT: INFO :
> main.py:parse_config: Snapshot cache support enabled. 09 Oct 2015
> 01:35:43 EDT: INFO : main.py:parse_config: Kernel cache support
> enabled. 09 Oct 2015 01:35:43 EDT: INFO : main.py:parse_config:
> Autoresuming support enabled. 09 Oct 2015 01:35:43 EDT: INFO :
> main.py:parse_config: Package cache support enabled. 09 Oct 2015
> 01:35:43 EDT: INFO : main.py:parse_config: Seed cache support
> enabled. 09 Oct 2015 01:35:43 EDT: INFO : main.py:parse_config:
> Envscript support enabled. 09 Oct 2015 01:35:43 EDT: DEBUG :
> main.py:main: conf_values[options] = set(['snapcache', 'kerncache',
> 'autoresume', 'pkgcache', 'bindist', 'seedcache']) ^C
>
> $ ./bin/wrapper.py -s test -C /asdf
> 09 Oct 2015 01:36:59 EDT: NOTICE : Using default Catalyst
> configuration file: /etc/catalyst/catalyst.conf ContentsMap:
> __init__(), search_order = ['pixz', 'lbzip2', 'isoinfo_l',
> 'squashfs', 'gzip', 'xz', 'bzip2', 'tar', 'isoinfo_f']
>
> !!! catalyst: Syntax error: 0
>
> 09 Oct 2015 01:36:59 EDT: CRITICAL: Could not parse commandline
> ---
> catalyst/log.py | 130
> +++++++++++++++++++++++++++++++++++++++++++++++++++++++
> catalyst/main.py | 30 ++++++++++++- 2 files changed, 158
> insertions(+), 2 deletions(-) create mode 100644 catalyst/log.py
>
> diff --git a/catalyst/log.py b/catalyst/log.py
> new file mode 100644
> index 0000000..bf39116
> --- /dev/null
> +++ b/catalyst/log.py
> @@ -0,0 +1,130 @@
> +# Copyright 2003-2015 Gentoo Foundation
> +# Distributed under the terms of the GNU General Public License v2
> +
> +"""Logging related code
> +
> +This largely exposes the same interface as the logging module except
> we add +another level "notice" between warning & info, and all output
> goes through +the "catalyst" logger.
> +"""
> +
> +from __future__ import print_function
> +
> +import logging
> +import logging.handlers
> +import os
> +import sys
> +import time
> +
> +
> +class CatalystLogger(logging.Logger):
> + """Override the _log member to autosplit on new lines"""
> +
> + def _log(self, level, msg, args, **kwargs):
> + """If given a multiline message, split it"""
> + # We have to interpolate it first in case they
> spread things out
> + # over multiple lines like: Bad Thing:\n%s\nGoodbye!
> + msg %= args
> + for line in msg.splitlines():
> + super(CatalystLogger, self)._log(level,
> line, (), **kwargs) +
> +
> +# The logger that all output should go through.
> +# This is ugly because we want to not perturb the logging module
> state. +_klass = logging.getLoggerClass()
> +logging.setLoggerClass(CatalystLogger)
> +logger = logging.getLogger('catalyst')
> +logging.setLoggerClass(_klass)
> +del _klass
> +
> +
> +# Set the notice level between warning and info.
> +NOTICE = (logging.WARNING + logging.INFO) / 2
> +logging.addLevelName(NOTICE, 'NOTICE')
> +
> +
> +# The API we expose to consumers.
> +def notice(msg, *args, **kwargs):
> + """Log a notice message"""
> + logger.log(NOTICE, msg, *args, **kwargs)
> +
> +def critical(msg, *args, **kwargs):
> + """Log a critical message and then exit"""
> + status = kwargs.pop('status', 1)
> + logger.critical(msg, *args, **kwargs)
> + sys.exit(status)
> +
> +error = logger.error
> +warning = logger.warning
> +info = logger.info
> +debug = logger.debug
> +
> +
> +class CatalystFormatter(logging.Formatter):
> + """Mark bad messages with colors automatically"""
> +
> + _COLORS = {
> + 'CRITICAL': '\033[1;35m',
> + 'ERROR': '\033[1;31m',
> + 'WARNING': '\033[1;33m',
> + 'DEBUG': '\033[1;34m',
> + }
> + _NORMAL = '\033[0m'
> +
> + @staticmethod
> + def detect_color():
> + """Figure out whether the runtime env wants color"""
> + if 'NOCOLOR' is os.environ:
> + return False
> + return os.isatty(sys.stdout.fileno())
> +
> + def __init__(self, *args, **kwargs):
> + """Initialize"""
> + color = kwargs.pop('color', None)
> + if color is None:
> + color = self.detect_color()
> + if not color:
> + self._COLORS = {}
> +
> + super(CatalystFormatter, self).__init__(*args,
> **kwargs) +
> + def format(self, record, **kwargs):
> + """Format the |record| with our color settings"""
> + #print(dir(record))
> + #print(record.getMessage())
> + msg = super(CatalystFormatter, self).format(record,
> **kwargs)
> + #print('{', msg, '}')
> + color = self._COLORS.get(record.levelname)
> + if color:
> + return color + msg + self._NORMAL
> + else:
> + return msg
> +
> +
> +def setup_logging(level, output=None, debug=False, color=None):
> + """Initialize the logging module using the |level| level"""
> + # The incoming level will be things like "info", but
> setLevel wants
> + # the numeric constant. Convert it here.
> + level = logging.getLevelName(level.upper())
> +
> + # The good stuff.
> + fmt = '%(asctime)s: %(levelname)-8s: '
> + if debug:
> + fmt += '%(filename)s:%(funcName)s: '
> + fmt += '%(message)s'
> +
> + # Figure out where to send the log output.
> + if output is None:
> + handler = logging.StreamHandler(stream=sys.stdout)
> + else:
> + handler = logging.FileHandler(output)
> +
> + # Use a date format that is readable by humans & machines.
> + # Think e-mail/RFC 2822: 05 Oct 2013 18:58:50 EST
> + tzname = time.strftime('%Z', time.localtime())
> + datefmt = '%d %b %Y %H:%M:%S ' + tzname
> + formatter = CatalystFormatter(fmt, datefmt, color=color)
> + handler.setFormatter(formatter)
> +
> + logger.addHandler(handler)
> + logger.setLevel(level)
> diff --git a/catalyst/main.py b/catalyst/main.py
> index e6b6447..c9a2219 100644
> --- a/catalyst/main.py
> +++ b/catalyst/main.py
> @@ -18,6 +18,7 @@ from DeComp.definitions import
> (COMPRESS_DEFINITIONS, DECOMPRESS_DEFINITIONS, CONTENTS_DEFINITIONS)
> from DeComp.contents import ContentsMap
>
> +from catalyst import log
> import catalyst.config
> import catalyst.util
> from catalyst.defaults import confdefaults, option_messages
> @@ -176,10 +177,23 @@ $ catalyst -f stage1-specfile.spec"""
> group = parser.add_argument_group('Program output options')
> group.add_argument('-d', '--debug',
> default=False, action='store_true',
> - help='enable debugging')
> + help='enable debugging (and default --log-level
> debug)') group.add_argument('-v', '--verbose',
> default=False, action='store_true',
> - help='verbose output')
> + help='verbose output (and default --log-level info)')
> + group.add_argument('--log-level',
> + default=None,
> + choices=('critical', 'error', 'warning', 'notice',
> 'info', 'debug'),
> + help='set verbosity of output')
> + group.add_argument('--log-file',
> + type=FilePath(exists=False),
> + help='write all output to this file (instead of
> stdout)')
> + group.add_argument('--color',
> + default=None, action='store_true',
> + help='colorize output all the time (default:
> detect)')
> + group.add_argument('--nocolor',
> + dest='color', action='store_false',
> + help='never colorize output all the time (default:
> detect)')
> group = parser.add_argument_group('Temporary file
> management') group.add_argument('-a', '--clear-autoresume',
> @@ -218,6 +232,18 @@ def main():
> parser = get_parser()
> opts = parser.parse_args(sys.argv[1:])
>
> + # Initialize the logger before anything else.
> + log_level = opts.log_level
> + if log_level is None:
> + if opts.debug:
> + log_level = 'debug'
> + elif opts.verbose:
> + log_level = 'info'
> + else:
> + log_level = 'notice'
> + log.setup_logging(log_level, output=opts.log_file,
> debug=opts.debug,
> + color=opts.color)
> +
> # Parse the command line options.
> myconfig = opts.config
> myspecfile = opts.file
Very nice. :) I learned a bit in here ;)
In gkeys I had it log to a file always, but didn't add color to the
console output.
--
Brian Dolbec <dolsen>
