From 79c36641a26c4aa02bf0eea7d70d22b8e98a99c8 Mon Sep 17 00:00:00 2001 From: lilydjwg Date: Wed, 11 Apr 2018 16:18:41 +0800 Subject: [PATCH] switch from logging to structlog --- nvchecker/core.py | 39 +++++++++++++--- nvchecker/get_version.py | 10 ++-- nvchecker/main.py | 7 +-- nvchecker/slogconf.py | 87 +++++++++++++++++++++++++++++++++++ nvchecker/sortversion.py | 4 -- nvchecker/source/anitya.py | 5 +- nvchecker/source/archpkg.py | 7 +-- nvchecker/source/aur.py | 9 ++-- nvchecker/source/cmd.py | 8 ++-- nvchecker/source/debianpkg.py | 7 +-- nvchecker/source/github.py | 13 ++++-- nvchecker/source/gitlab.py | 9 ++-- nvchecker/source/regex.py | 9 ++-- nvchecker/source/ubuntupkg.py | 9 ++-- nvchecker/source/vcs.py | 11 +++-- nvchecker/tools.py | 8 ++-- 16 files changed, 183 insertions(+), 59 deletions(-) create mode 100644 nvchecker/slogconf.py diff --git a/nvchecker/core.py b/nvchecker/core.py index abf424f..7ac239a 100644 --- a/nvchecker/core.py +++ b/nvchecker/core.py @@ -1,25 +1,30 @@ # vim: se sw=2: # MIT licensed -# Copyright (c) 2013-2017 lilydjwg , et al. +# Copyright (c) 2013-2018 lilydjwg , et al. import os import sys -import logging import configparser import asyncio +import logging +import structlog from .lib import nicelogger from .get_version import get_version from .source import session +from . import slogconf from . import __version__ -logger = logging.getLogger(__name__) +logger = structlog.get_logger(logger_name=__name__) def add_common_arguments(parser): parser.add_argument('-l', '--logging', choices=('debug', 'info', 'warning', 'error'), default='info', help='logging level (default: info)') + parser.add_argument('--logger', choices=['stdlib', 'structlog'], + default='stdlib', + help='select which logger to use') parser.add_argument('-V', '--version', action='store_true', help='show version and exit') parser.add_argument('file', metavar='FILE', nargs='?', type=open, @@ -27,7 +32,27 @@ def add_common_arguments(parser): def process_common_arguments(args): '''return True if should stop''' - nicelogger.enable_pretty_logging(getattr(logging, args.logging.upper())) + if args.logger == 'stdlib': + slogconf.fix_logging() + nicelogger.enable_pretty_logging( + getattr(logging, args.logging.upper())) + structlog.configure( + processors=[ + slogconf.exc_info, + slogconf.stdlib_renderer, + ], + logger_factory=structlog.PrintLoggerFactory( + file=open(os.devnull, 'w')), + ) + else: + structlog.configure( + processors=[ + slogconf.exc_info, + structlog.processors.format_exc_info, + slogconf.json_renderer, + ], + logger_factory=structlog.PrintLoggerFactory(file=sys.stderr), + ) if args.version: progname = os.path.basename(sys.argv[0]) @@ -129,16 +154,16 @@ class Source: if version is not None: self.print_version_update(name, version) except Exception: - logger.exception('unexpected error happened with %s', name) + logger.exception('unexpected error happened', name=name) def print_version_update(self, name, version): oldver = self.oldvers.get(name, None) if not oldver or oldver != version: - logger.info('%s updated to %s', name, version) + logger.info('updated', name=name, version=version, old_version=oldver) self.curvers[name] = version self.on_update(name, version, oldver) else: - logger.debug('%s current %s', name, version) + logger.debug('up-to-date', name=name, version=version) def on_update(self, name, version, oldver): pass diff --git a/nvchecker/get_version.py b/nvchecker/get_version.py index 0b66e91..e7a4810 100644 --- a/nvchecker/get_version.py +++ b/nvchecker/get_version.py @@ -1,11 +1,13 @@ # MIT licensed # Copyright (c) 2013-2017 lilydjwg , et al. -import logging import re from importlib import import_module -logger = logging.getLogger(__name__) +import structlog + +logger = structlog.get_logger(logger_name=__name__) + handler_precedence = ( 'github', 'aur', 'pypi', 'archpkg', 'debianpkg', 'ubuntupkg', 'gems', 'pacman', @@ -46,7 +48,7 @@ async def get_version(name, conf): try: version = substitute_version(version, name, conf) except (ValueError, re.error): - logger.exception('error occurred in version substitutions for %s', name) + logger.exception('error occurred in version substitutions', name=name) return version else: - logger.error('%s: no idea to get version info.', name) + logger.error('no idea to get version info.', name=name) diff --git a/nvchecker/main.py b/nvchecker/main.py index b1a8041..f1c27a0 100755 --- a/nvchecker/main.py +++ b/nvchecker/main.py @@ -2,15 +2,16 @@ # MIT licensed # Copyright (c) 2013-2017 lilydjwg , et al. -import logging import argparse - import asyncio +import structlog + from .lib import notify from . import core -logger = logging.getLogger(__name__) +logger = structlog.get_logger(logger_name=__name__) + notifications = [] args = None diff --git a/nvchecker/slogconf.py b/nvchecker/slogconf.py new file mode 100644 index 0000000..5e5e4bb --- /dev/null +++ b/nvchecker/slogconf.py @@ -0,0 +1,87 @@ +# vim: se sw=2: +# MIT licensed +# Copyright (c) 2018 lilydjwg , et al. + +import logging +import os +import io +import traceback + +import structlog + +def _console_msg(event): + evt = event['event'] + if evt == 'up-to-date': + msg = 'up-to-date, version %s' % event['version'] + elif evt == 'updated': + if event.get('old_version'): + msg = 'updated from %(old_version)s to %(version)s' % event + else: + msg = 'updated to %(version)s' % event + else: + msg = evt + + if 'name' in event: + msg = '%s: %s' % (event['name'], msg) + del event['name'] + + event['msg'] = msg + + return event + +def exc_info(logger, level, event): + if level == 'exception': + event['exc_info'] = True + return event + +def stdlib_renderer(logger, level, event): + event = _console_msg(event) + logger = logging.getLogger(event.get('logger_name')) + msg = event.pop('msg', event['event']) + exc_info = event.pop('exc_info', None) + getattr(logger, level)( + msg, exc_info = exc_info, extra=event, + ) + return '' + +_renderer = structlog.processors.JSONRenderer(ensure_ascii=False) +def json_renderer(logger, level, event): + return _renderer(logger, level, event) + +class _Logger(logging.Logger): + _my_srcfile = os.path.normcase( + stdlib_renderer.__code__.co_filename) + + def findCaller(self, stack_info=False): + """ + Find the stack frame of the caller so that we can note the source + file name, line number and function name. + """ + f = logging.currentframe() + #On some versions of IronPython, currentframe() returns None if + #IronPython isn't run with -X:Frames. + if f is not None: + f = f.f_back + rv = "(unknown file)", 0, "(unknown function)", None + while hasattr(f, "f_code"): + co = f.f_code + filename = os.path.normcase(co.co_filename) + if filename in [logging._srcfile, self._my_srcfile]: + f = f.f_back + continue + sinfo = None + if stack_info: + sio = io.StringIO() + sio.write('Stack (most recent call last):\n') + traceback.print_stack(f, file=sio) + sinfo = sio.getvalue() + if sinfo[-1] == '\n': + sinfo = sinfo[:-1] + sio.close() + rv = (co.co_filename, f.f_lineno, co.co_name, sinfo) + break + return rv + +def fix_logging(): + logging.setLoggerClass(_Logger) + diff --git a/nvchecker/sortversion.py b/nvchecker/sortversion.py index 4f117ec..739a104 100644 --- a/nvchecker/sortversion.py +++ b/nvchecker/sortversion.py @@ -7,12 +7,8 @@ Sort versions using pkg_resource.parse_version or pyalpm.vercmp __all__ = ["sort_version_keys"] -import logging - from functools import cmp_to_key -logger = logging.getLogger(__name__) - from pkg_resources import parse_version try: import pyalpm diff --git a/nvchecker/source/anitya.py b/nvchecker/source/anitya.py index d3d035e..e988dd1 100644 --- a/nvchecker/source/anitya.py +++ b/nvchecker/source/anitya.py @@ -1,10 +1,11 @@ # MIT licensed # Copyright (c) 2017 lilydjwg , et al. -import logging +import structlog + from . import session -logger = logging.getLogger(__name__) +logger = structlog.get_logger(logger_name=__name__) URL = 'https://release-monitoring.org/api/project/{pkg}' diff --git a/nvchecker/source/archpkg.py b/nvchecker/source/archpkg.py index aac2cc0..c2f1037 100644 --- a/nvchecker/source/archpkg.py +++ b/nvchecker/source/archpkg.py @@ -1,10 +1,11 @@ # MIT licensed # Copyright (c) 2013-2017 lilydjwg , et al. -import logging +import structlog + from . import session -logger = logging.getLogger(__name__) +logger = structlog.get_logger(logger_name=__name__) URL = 'https://www.archlinux.org/packages/search/json/' @@ -15,7 +16,7 @@ async def get_version(name, conf): data = await res.json() if not data['results']: - logger.error('Arch package not found: %s', name) + logger.error('Arch package not found', name=name) return r = [r for r in data['results'] if r['repo'] != 'testing'][0] diff --git a/nvchecker/source/aur.py b/nvchecker/source/aur.py index 79cc72d..1d1da00 100644 --- a/nvchecker/source/aur.py +++ b/nvchecker/source/aur.py @@ -1,12 +1,13 @@ # MIT licensed # Copyright (c) 2013-2017 lilydjwg , et al. -import logging +import structlog + from . import session -AUR_URL = 'https://aur.archlinux.org/rpc/?v=5&type=info&arg[]=' +logger = structlog.get_logger(logger_name=__name__) -logger = logging.getLogger(__name__) +AUR_URL = 'https://aur.archlinux.org/rpc/?v=5&type=info&arg[]=' async def get_version(name, conf): aurname = conf.get('aur') or name @@ -15,7 +16,7 @@ async def get_version(name, conf): data = await res.json() if not data['results']: - logger.error('AUR upstream not found for %s', name) + logger.error('AUR upstream not found', name=name) return version = data['results'][0]['Version'] diff --git a/nvchecker/source/cmd.py b/nvchecker/source/cmd.py index dcfa307..124f9fe 100644 --- a/nvchecker/source/cmd.py +++ b/nvchecker/source/cmd.py @@ -1,10 +1,11 @@ # MIT licensed # Copyright (c) 2013-2017 lilydjwg , et al. -import logging import asyncio -logger = logging.getLogger(__name__) +import structlog + +logger = structlog.get_logger(logger_name=__name__) async def get_version(name, conf): cmd = conf['cmd'] @@ -12,7 +13,8 @@ async def get_version(name, conf): output = (await p.communicate())[0].strip().decode('latin1') if p.returncode != 0: - logger.error('%s: command exited with %d.', name, p.returncode) + logger.error('command exited with error', + name=name, returncode=p.returncode) return return output diff --git a/nvchecker/source/debianpkg.py b/nvchecker/source/debianpkg.py index 544133e..0906a69 100644 --- a/nvchecker/source/debianpkg.py +++ b/nvchecker/source/debianpkg.py @@ -1,10 +1,11 @@ # MIT licensed # Copyright (c) 2017 Felix Yan , et al. -import logging +import structlog + from . import session -logger = logging.getLogger(__name__) +logger = structlog.get_logger(logger_name=__name__) URL = 'https://sources.debian.org/api/src/%(pkgname)s/?suite=%(suite)s' @@ -17,7 +18,7 @@ async def get_version(name, conf): data = await res.json() if not data.get('versions'): - logger.error('Debian package not found: %s', name) + logger.error('Debian package not found', name=name) return r = data['versions'][0] diff --git a/nvchecker/source/github.py b/nvchecker/source/github.py index c7deb16..b501fa4 100644 --- a/nvchecker/source/github.py +++ b/nvchecker/source/github.py @@ -2,17 +2,18 @@ # Copyright (c) 2013-2017 lilydjwg , et al. import os -import logging + +import structlog from . import session from ..sortversion import sort_version_keys +logger = structlog.get_logger(logger_name=__name__) + GITHUB_URL = 'https://api.github.com/repos/%s/commits' GITHUB_LATEST_RELEASE = 'https://api.github.com/repos/%s/releases/latest' GITHUB_MAX_TAG = 'https://api.github.com/repos/%s/tags' -logger = logging.getLogger(__name__) - async def get_version(name, conf): repo = conf.get('github') br = conf.get('branch') @@ -42,14 +43,16 @@ async def get_version(name, conf): data = await res.json() if use_latest_release: if 'tag_name' not in data: - logger.error('%s: No tag found in upstream repository.', name) + logger.error('No tag found in upstream repository.', + name=name) return version = data['tag_name'] elif use_max_tag: data = [tag["name"] for tag in data if tag["name"] not in ignored_tags] data.sort(key=sort_version_key) if not len(data): - logger.error('%s: No tag found in upstream repository.', name) + logger.error('No tag found in upstream repository.', + name=name) return version = data[-1] else: diff --git a/nvchecker/source/gitlab.py b/nvchecker/source/gitlab.py index 2809f77..4a1cba1 100644 --- a/nvchecker/source/gitlab.py +++ b/nvchecker/source/gitlab.py @@ -2,17 +2,18 @@ # Copyright (c) 2013-2017 lilydjwg , et al. import os -import logging import urllib.parse +import structlog + from . import session from ..sortversion import sort_version_keys +logger = structlog.get_logger(logger_name=__name__) + GITLAB_URL = 'https://%s/api/v3/projects/%s/repository/commits?ref_name=%s' GITLAB_MAX_TAG = 'https://%s/api/v3/projects/%s/repository/tags' -logger = logging.getLogger(__name__) - async def get_version(name, conf): repo = urllib.parse.quote_plus(conf.get('gitlab')) br = conf.get('branch', 'master') @@ -24,7 +25,7 @@ async def get_version(name, conf): env_name = "NVCHECKER_GITLAB_TOKEN_" + host.upper().replace(".", "_").replace("/", "_") token = conf.get('token', os.environ.get(env_name, None)) if token is None: - logger.error('%s: No gitlab token specified.', name) + logger.error('No gitlab token specified.', name=name) return if use_max_tag: diff --git a/nvchecker/source/regex.py b/nvchecker/source/regex.py index fd8b66e..da0c912 100644 --- a/nvchecker/source/regex.py +++ b/nvchecker/source/regex.py @@ -3,18 +3,19 @@ import re import sre_constants -import logging + +import structlog from . import session from ..sortversion import sort_version_keys -logger = logging.getLogger(__name__) +logger = structlog.get_logger(logger_name=__name__) async def get_version(name, conf): try: regex = re.compile(conf['regex']) except sre_constants.error: - logger.warn('%s: bad regex, skipped.', name, exc_info=True) + logger.warn('bad regex, skipped.', name=name, exc_info=True) return encoding = conf.get('encoding', 'latin1') @@ -33,5 +34,5 @@ async def get_version(name, conf): version = max(regex.findall(body), key=sort_version_key) except ValueError: version = None - logger.error('%s: version string not found.', name) + logger.error('version string not found.', name=name) return version diff --git a/nvchecker/source/ubuntupkg.py b/nvchecker/source/ubuntupkg.py index b6fa40b..ea72106 100644 --- a/nvchecker/source/ubuntupkg.py +++ b/nvchecker/source/ubuntupkg.py @@ -1,10 +1,11 @@ # MIT licensed # Copyright (c) 2017 Felix Yan , et al. -import logging +import structlog + from . import session -logger = logging.getLogger(__name__) +logger = structlog.get_logger(logger_name=__name__) URL = 'https://api.launchpad.net/1.0/ubuntu/+archive/primary?ws.op=getPublishedSources&source_name=%s&exact_match=true' @@ -24,7 +25,7 @@ async def get_version(name, conf): data = await res.json() if not data.get('entries'): - logger.error('Ubuntu package not found: %s', name) + logger.error('Ubuntu package not found', name=name) return releases = [r for r in data["entries"] if r["status"] == "Published"] @@ -38,7 +39,7 @@ async def get_version(name, conf): url = data["next_collection_link"] if not releases: - logger.error('Ubuntu package not found: %s', name) + logger.error('Ubuntu package not found', name=name) return if strip_release: diff --git a/nvchecker/source/vcs.py b/nvchecker/source/vcs.py index e1fffac..62fdd4c 100644 --- a/nvchecker/source/vcs.py +++ b/nvchecker/source/vcs.py @@ -1,13 +1,13 @@ # MIT licensed # Copyright (c) 2013-2017 lilydjwg , et al. -import logging import asyncio -from pkg_resources import parse_version - import os.path as _path -logger = logging.getLogger(__name__) +from pkg_resources import parse_version +import structlog + +logger = structlog.get_logger(logger_name=__name__) _self_path = _path.dirname(_path.abspath(__file__)) _cmd_prefix = ['/bin/bash', _path.join(_self_path, 'vcs.sh')] @@ -38,7 +38,8 @@ async def get_version(name, conf): output = (await p.communicate())[0].strip().decode('latin1') if p.returncode != 0: - logger.error('%s: command exited with %d.', name, p.returncode) + logger.error('command exited with error', + name=name, returncode=p.returncode) return else: if use_max_tag: diff --git a/nvchecker/tools.py b/nvchecker/tools.py index 8b35a60..dafd5c3 100644 --- a/nvchecker/tools.py +++ b/nvchecker/tools.py @@ -5,11 +5,11 @@ import sys import os import argparse -import logging +import structlog from . import core -logger = logging.getLogger(__name__) +logger = structlog.get_logger(logger_name=__name__) def take(): parser = argparse.ArgumentParser(description='update version records of nvchecker') @@ -25,7 +25,7 @@ def take(): s = core.Source(args.file) if not s.oldver or not s.newver: logger.fatal( - "%s doesn't have both 'oldver' and 'newver' set.", s + "doesn't have both 'oldver' and 'newver' set.", source=s, ) sys.exit(2) @@ -40,7 +40,7 @@ def take(): oldvers[name] = newvers[name] except KeyError: logger.fatal( - "%s doesn't exist in 'newver' set.", name + "doesn't exist in 'newver' set.", name=name, ) sys.exit(2)