From 64b607c42f73caf1a494e0b88621397d03994001 Mon Sep 17 00:00:00 2001
From: Andre Anjos <andre.dos.anjos@gmail.com>
Date: Mon, 7 Jan 2019 18:11:50 +0100
Subject: [PATCH] [logging] Fix logging for all commands
---
bob/devtools/log.py | 140 +++++++++++++++++++++++++++++
bob/devtools/scripts/bdt.py | 69 +-------------
bob/devtools/scripts/cb_output.py | 6 +-
bob/devtools/scripts/changelog.py | 31 ++++---
bob/devtools/scripts/lasttag.py | 6 +-
bob/devtools/scripts/release.py | 24 ++---
bob/devtools/scripts/visibility.py | 17 ++--
doc/api.rst | 3 +
8 files changed, 198 insertions(+), 98 deletions(-)
create mode 100644 bob/devtools/log.py
diff --git a/bob/devtools/log.py b/bob/devtools/log.py
new file mode 100644
index 00000000..a623ccae
--- /dev/null
+++ b/bob/devtools/log.py
@@ -0,0 +1,140 @@
+#!/usr/bin/env python
+# -*- coding: utf-8 -*-
+
+"""Sets-up logging, centrally for Bob.
+"""
+
+import sys
+import logging
+
+# get the default root logger of Bob
+_logger = logging.getLogger('bob')
+
+# by default, warning and error messages should be written to sys.stderr
+_warn_err = logging.StreamHandler(sys.stderr)
+_warn_err.setLevel(logging.WARNING)
+_logger.addHandler(_warn_err)
+
+# debug and info messages are written to sys.stdout
+
+class _InfoFilter:
+ def filter(self, record):
+ return record.levelno <= logging.INFO
+
+
+_debug_info = logging.StreamHandler(sys.stdout)
+_debug_info.setLevel(logging.DEBUG)
+_debug_info.addFilter(_InfoFilter())
+_logger.addHandler(_debug_info)
+
+
+# helper functions to instantiate and set-up logging
+def setup(logger_name,
+ format="%(name)s@%(asctime)s -- %(levelname)s: %(message)s"):
+ """This function returns a logger object that is set up to perform logging
+ using Bob loggers.
+
+ Parameters
+ ----------
+ logger_name : str
+ The name of the module to generate logs for
+ format : :obj:`str`, optional
+ The format of the logs, see :py:class:`logging.LogRecord` for more
+ details. By default, the log contains the logger name, the log time, the
+ log level and the massage.
+
+ Returns
+ -------
+ logger : :py:class:`logging.Logger`
+ The logger configured for logging. The same logger can be retrieved using
+ the :py:func:`logging.getLogger` function.
+ """
+ # generate new logger object
+ logger = logging.getLogger(logger_name)
+
+ # add log the handlers if not yet done
+ if not logger_name.startswith("bob") and not logger.handlers:
+ logger.addHandler(_warn_err)
+ logger.addHandler(_debug_info)
+
+ # this formats the logger to print the desired information
+ formatter = logging.Formatter(format)
+ # we have to set the formatter to all handlers registered in the current
+ # logger
+ for handler in logger.handlers:
+ handler.setFormatter(formatter)
+
+ # set the same formatter for bob loggers
+ for handler in _logger.handlers:
+ handler.setFormatter(formatter)
+
+ return logger
+
+
+def set_verbosity_level(logger, level):
+ """Sets the log level for the given logger.
+
+ Parameters
+ ----------
+ logger : :py:class:`logging.Logger` or str
+ The logger to generate logs for, or the name of the module to generate
+ logs for.
+ level : int
+ Possible log levels are: 0: Error; 1: Warning; 2: Info; 3: Debug.
+
+ Raises
+ ------
+ ValueError
+ If the level is not in range(0, 4).
+ """
+ if level not in range(0, 4):
+ raise ValueError(
+ "The verbosity level %d does not exist. Please reduce the number of "
+ "'--verbose' parameters in your command line" % level)
+ # set up the verbosity level of the logging system
+ log_level = {
+ 0: logging.ERROR,
+ 1: logging.WARNING,
+ 2: logging.INFO,
+ 3: logging.DEBUG
+ }[level]
+
+ # set this log level to the logger with the specified name
+ if isinstance(logger, str):
+ logger = logging.getLogger(logger)
+ logger.setLevel(log_level)
+ # set the same log level for the bob logger
+ _logger.setLevel(log_level)
+
+
+def verbosity_option(**kwargs):
+ """Adds a -v/--verbose option to a click command.
+
+ Parameters
+ ----------
+ **kwargs
+ All kwargs are passed to click.option.
+
+ Returns
+ -------
+ callable
+ A decorator to be used for adding this option.
+ """
+ global _logger
+ import click
+
+ def custom_verbosity_option(f):
+ def callback(ctx, param, value):
+ ctx.meta['verbosity'] = value
+ set_verbosity_level(_logger, value)
+ _logger.debug("`bob' logging level set to %d", value)
+ return value
+ return click.option(
+ '-v', '--verbose', count=True,
+ expose_value=False, default=0,
+ help="Increase the verbosity level from 0 (only error messages) "
+ "to 1 (warnings), 2 (info messages), 3 (debug information) by "
+ "adding the --verbose option as often as desired "
+ "(e.g. '-vvv' for debug).",
+ callback=callback, **kwargs)(f)
+ return custom_verbosity_option
diff --git a/bob/devtools/scripts/bdt.py b/bob/devtools/scripts/bdt.py
index 4af5720c..846a5177 100644
--- a/bob/devtools/scripts/bdt.py
+++ b/bob/devtools/scripts/bdt.py
@@ -9,72 +9,8 @@ import pkg_resources
import click
from click_plugins import with_plugins
-import logging
-logger = logging.getLogger('bdt')
-
-
-def set_verbosity_level(logger, level):
- """Sets the log level for the given logger.
-
- Parameters
- ----------
- logger : :py:class:`logging.Logger` or str
- The logger to generate logs for, or the name of the module to generate
- logs for.
- level : int
- Possible log levels are: 0: Error; 1: Warning; 2: Info; 3: Debug.
- Raises
- ------
- ValueError
- If the level is not in range(0, 4).
- """
- if level not in range(0, 4):
- raise ValueError(
- "The verbosity level %d does not exist. Please reduce the number "
- "of '--verbose' parameters in your command line" % level
- )
- # set up the verbosity level of the logging system
- log_level = {
- 0: logging.ERROR,
- 1: logging.WARNING,
- 2: logging.INFO,
- 3: logging.DEBUG
- }[level]
-
- # set this log level to the logger with the specified name
- if isinstance(logger, str):
- logger = logging.getLogger(logger)
- logger.setLevel(log_level)
-
-
-def verbosity_option(**kwargs):
- """Adds a -v/--verbose option to a click command.
-
- Parameters
- ----------
- **kwargs
- All kwargs are passed to click.option.
-
- Returns
- -------
- callable
- A decorator to be used for adding this option.
- """
- def custom_verbosity_option(f):
- def callback(ctx, param, value):
- ctx.meta['verbosity'] = value
- set_verbosity_level(logger, value)
- logger.debug("`bdt' logging level set to %d", value)
- return value
- return click.option(
- '-v', '--verbose', count=True,
- expose_value=False, default=2,
- help="Increase the verbosity level from 0 (only error messages) "
- "to 1 (warnings), 2 (info messages), 3 (debug information) by "
- "adding the --verbose option as often as desired "
- "(e.g. '-vvv' for debug).",
- callback=callback, **kwargs)(f)
- return custom_verbosity_option
+from ..log import setup
+logger = setup('bob')
class AliasedGroup(click.Group):
@@ -114,6 +50,5 @@ def raise_on_error(view_func):
@with_plugins(pkg_resources.iter_entry_points('bdt.cli'))
@click.group(cls=AliasedGroup,
context_settings=dict(help_option_names=['-?', '-h', '--help']))
-@verbosity_option()
def main():
"""Bob Development Tools - see available commands below"""
diff --git a/bob/devtools/scripts/cb_output.py b/bob/devtools/scripts/cb_output.py
index 35c98c0d..cfebdb64 100644
--- a/bob/devtools/scripts/cb_output.py
+++ b/bob/devtools/scripts/cb_output.py
@@ -1,12 +1,15 @@
#!/usr/bin/env python
# -*- coding: utf-8 -*-
+import logging
+logger = logging.getLogger(__name__)
+
import click
from click.testing import CliRunner
import conda_build.api as cb
from . import bdt
-
+from ..log import verbosity_option
from ..conda import should_skip_build
@@ -23,6 +26,7 @@ $ bdt cb-output ../bob.conda/conda/kaldi -m ../bob.admin/gitlab/conda_build_conf
@click.argument('recipe_path')
@click.option('-m', '--variant-config-files', help='see conda build --help')
@click.option('--python', help='see conda build --help')
+@verbosity_option()
@bdt.raise_on_error
def cb_output(recipe_path, variant_config_files, python):
"""Outputs name(s) of package(s) that would be generated by conda build.
diff --git a/bob/devtools/scripts/changelog.py b/bob/devtools/scripts/changelog.py
index af80b7a7..a347f89d 100644
--- a/bob/devtools/scripts/changelog.py
+++ b/bob/devtools/scripts/changelog.py
@@ -4,9 +4,13 @@ import os
import sys
import datetime
+import logging
+logger = logging.getLogger(__name__)
+
import click
from . import bdt
+from ..log import verbosity_option
from ..changelog import get_last_tag_date, write_tags_with_commits
from ..changelog import parse_date
from ..release import get_gitlab_instance
@@ -21,24 +25,24 @@ Examples:
1. Generates the changelog for a single package using merge requests:
- $ bdt -vvv changelog group/package.xyz changelog.md
+ $ bdt changelog group/package.xyz changelog.md
2. The same as above, but dumps the changelog to stdout instead of a file:
- $ bdt -vvv changelog group/package.xyz
+ $ bdt changelog group/package.xyz
3. Generates the changelog for a single package looking at commits
(not merge requests):
- $ bdt -vvv changelog --mode=commits group/package.xyz changelog.md
+ $ bdt changelog --mode=commits group/package.xyz changelog.md
4. Generates the changelog for a single package looking at merge requests starting from a given date of January 1, 2016:
\b
- $ bdt -vvv changelog --mode=mrs --since=2016-01-01 group/package.xyz changelog.md
+ $ bdt changelog --mode=mrs --since=2016-01-01 group/package.xyz changelog.md
5. Generates a complete list of changelogs for a list of packages (one per line:
@@ -47,7 +51,7 @@ Examples:
$ curl -o order.txt https://gitlab.idiap.ch/bob/bob.nightlies/raw/master/order.txt
$ bdt lasttag bob/bob
# copy and paste date to next command
- $ bdt -vvv changelog --since="2018-07-17 10:23:40" order.txt changelog.md
+ $ bdt changelog --since="2018-07-17 10:23:40" order.txt changelog.md
''')
@click.argument('target')
@click.argument('changelog', type=click.Path(exists=False, dir_okay=False,
@@ -67,6 +71,7 @@ Examples:
'(see https://dateutil.readthedocs.io/en/stable/parser.html) from ' \
'which you want to generate the changelog. If not set, the package\'s' \
'last release date will be used')
+@verbosity_option()
@bdt.raise_on_error
def changelog(target, changelog, group, mode, since):
"""Generates changelog file for package(s) from the Gitlab server.
@@ -90,13 +95,13 @@ def changelog(target, changelog, group, mode, since):
# reads package list or considers name to be a package name
if os.path.exists(target) and os.path.isfile(target):
- bdt.logger.info('Reading package names from file %s...', target)
+ logger.info('Reading package names from file %s...', target)
with open(target, 'rt') as f:
packages = [k.strip() for k in f.readlines() if k.strip() and not \
k.strip().startswith('#')]
else:
- bdt.logger.info('Assuming %s is a package name (file does not ' \
- 'exist)...', target)
+ logger.info('Assuming %s is a package name (file does not exist)...',
+ target)
packages = [target]
# if the user passed a date, convert it
@@ -110,11 +115,11 @@ def changelog(target, changelog, group, mode, since):
# retrieves the gitlab package object
use_package = gl.projects.get(package)
- bdt.logger.info('Found gitlab project %s (id=%d)',
+ logger.info('Found gitlab project %s (id=%d)',
use_package.attributes['path_with_namespace'], use_package.id)
last_release_date = since or get_last_tag_date(use_package)
- bdt.logger.info('Retrieving data (mode=%s) since %s', mode,
+ logger.info('Retrieving data (mode=%s) since %s', mode,
last_release_date.strftime('%b %d, %Y %H:%M'))
# add 1s to avoid us retrieving previous release data
@@ -127,13 +132,13 @@ def changelog(target, changelog, group, mode, since):
if use_package.attributes['namespace'] == use_package.name:
# skip system meta-package
- bdt.logger.warn('Skipping meta package %s...',
+ logger.warn('Skipping meta package %s...',
use_package.attributes['path_with_namespace'])
continue
if use_package.attributes['visibility'] not in visibility:
- bdt.logger.warn('Skipping package %s (visibility not in ' \
- '"%s")...', use_package.attributes['path_with_namespace'],
+ logger.warn('Skipping package %s (visibility not in "%s")...',
+ use_package.attributes['path_with_namespace'],
'|'.join(visibility))
continue
diff --git a/bob/devtools/scripts/lasttag.py b/bob/devtools/scripts/lasttag.py
index 2826ad18..d1e2aa27 100644
--- a/bob/devtools/scripts/lasttag.py
+++ b/bob/devtools/scripts/lasttag.py
@@ -1,10 +1,13 @@
#!/usr/bin/env python
import os
+import logging
+logger = logging.getLogger(__name__)
import click
from . import bdt
+from ..log import verbosity_option
from ..changelog import get_last_tag, parse_date
from ..release import get_gitlab_instance
@@ -27,6 +30,7 @@ Examples:
''')
@click.argument('package')
+@verbosity_option()
@bdt.raise_on_error
def lasttag(package):
"""Returns the last tag information on a given PACKAGE
@@ -39,7 +43,7 @@ def lasttag(package):
# we lookup the gitlab group once
use_package = gl.projects.get(package)
- bdt.logger.info('Found gitlab project %s (id=%d)',
+ logger.info('Found gitlab project %s (id=%d)',
use_package.attributes['path_with_namespace'], use_package.id)
tag = get_last_tag(use_package)
diff --git a/bob/devtools/scripts/release.py b/bob/devtools/scripts/release.py
index 63b8374f..251539fc 100644
--- a/bob/devtools/scripts/release.py
+++ b/bob/devtools/scripts/release.py
@@ -3,10 +3,13 @@
import os
+import logging
+logger = logging.getLogger(__name__)
import click
from . import bdt
+from ..log import verbosity_option
from ..release import release_bob, parse_and_process_package_changelog
from ..release import release_package, wait_for_pipeline_to_finish
from ..release import get_gitlab_instance
@@ -20,28 +23,28 @@ Examples:
1. Releases a single package:
- $ bdt -vvv release --package=bob.package.xyz changelog.md
+ $ bdt release --package=bob.package.xyz changelog.md
2. If there is a single package in the ``changelog.md`` file, the flag
``--package`` is not required:
- $ bdt -vvv release changelog.md
+ $ bdt release changelog.md
2. Releases the whole of bob using `changelog_since_last_release.md`:
- $ bdt -vvv release bob/devtools/data/changelog_since_last_release.md
+ $ bdt release bob/devtools/data/changelog_since_last_release.md
3. In case of errors, resume the release of the whole of Bob:
- $ bdt -vvv release --resume bob/devtools/data/changelog_since_last_release.md
+ $ bdt release --resume bob/devtools/data/changelog_since_last_release.md
4. The option `-dry-run` can be used to let the script print what it would do instead of actually doing it:
- $ bdt -vvv release --dry-run changelog_since_last_release.md
+ $ bdt release --dry-run changelog_since_last_release.md
'''
)
@click.argument('changelog', type=click.File('rb', lazy=False))
@@ -59,6 +62,7 @@ Examples:
help='Only goes through the actions, but does not execute them ' \
'(combine with the verbosity flags - e.g. ``-vvv``) to enable ' \
'printing to help you understand what will be done')
+@verbosity_option()
@bdt.raise_on_error
def release(changelog, group, package, resume, dry_run):
"""\b
@@ -149,7 +153,7 @@ def release(changelog, group, package, resume, dry_run):
if line[1:].strip() == package]
if not start_idx:
- bdt.logger.error('Package %s was not found in the changelog',
+ logger.error('Package %s was not found in the changelog',
package)
return
@@ -157,14 +161,14 @@ def release(changelog, group, package, resume, dry_run):
# if we are in a dry-run mode, let's let it be known
if dry_run:
- bdt.logger.warn('!!!! DRY RUN MODE !!!!')
- bdt.logger.warn('Nothing is being committed to Gitlab')
+ logger.warn('!!!! DRY RUN MODE !!!!')
+ logger.warn('Nothing is being committed to Gitlab')
# go through the list of packages and release them starting from the
# start_idx
for i in range(start_idx, len(pkgs) - 1):
cur_package_name = changelogs[pkgs[i]][1:].strip()
- bdt.logger.info('Processing package %s', changelogs[pkgs[i]])
+ logger.info('Processing package %s', changelogs[pkgs[i]])
gitpkg, tag, tag_comments = parse_and_process_package_changelog(gl,
use_group, cur_package_name,
changelogs[pkgs[i] + 1: pkgs[i + 1]], dry_run)
@@ -181,4 +185,4 @@ def release(changelog, group, package, resume, dry_run):
if package == cur_package_name and not resume:
break
- bdt.logger.info('Finished processing %s', changelog)
+ logger.info('Finished processing %s', changelog)
diff --git a/bob/devtools/scripts/visibility.py b/bob/devtools/scripts/visibility.py
index 0ef0bc18..67321c26 100644
--- a/bob/devtools/scripts/visibility.py
+++ b/bob/devtools/scripts/visibility.py
@@ -6,7 +6,11 @@ import sys
import click
import gitlab
+import logging
+logger = logging.getLogger(__name__)
+
from . import bdt
+from ..log import verbosity_option
from ..release import get_gitlab_instance
@@ -19,20 +23,21 @@ Examples:
1. Check the visibility of a package you can access
- $ bdt -vvv visibility bob/bob.extension
+ $ bdt visibility bob/bob.extension
2. Checks the visibility of all packages in a file list:
\b
$ curl -o order.txt https://gitlab.idiap.ch/bob/bob.nightlies/raw/master/order.txt
- $ bdt -vvv visibility order.txt
+ $ bdt visibility order.txt
''')
@click.argument('target')
@click.option('-g', '--group', default='bob', show_default=True,
help='Gitlab default group name where packages are located (if not ' \
'specified using a "/" on the package name - e.g. ' \
'"bob/bob.extension")')
+@verbosity_option()
@bdt.raise_on_error
def visibility(target, group):
"""Checks if the gitlab repository is visible to the current user
@@ -47,12 +52,12 @@ def visibility(target, group):
# reads package list or considers name to be a package name
if os.path.exists(target) and os.path.isfile(target):
- bdt.logger.info('Reading package names from file %s...', target)
+ logger.info('Reading package names from file %s...', target)
with open(target, 'rt') as f:
packages = [k.strip() for k in f.readlines() if k.strip() and not \
k.strip().startswith('#')]
else:
- bdt.logger.info('Assuming %s is a package name (file does not ' \
+ logger.info('Assuming %s is a package name (file does not ' \
'exist)...', target)
packages = [target]
@@ -65,11 +70,11 @@ def visibility(target, group):
# retrieves the gitlab package object
try:
use_package = gl.projects.get(package)
- bdt.logger.info('Found gitlab project %s (id=%d)',
+ logger.info('Found gitlab project %s (id=%d)',
use_package.attributes['path_with_namespace'], use_package.id)
click.echo('%s: %s' % (package,
use_package.attributes['visibility'].lower()))
except gitlab.GitlabGetError as e:
- bdt.logger.warn('Gitlab access error - package %s does not exist?',
+ logger.warn('Gitlab access error - package %s does not exist?',
package)
click.echo('%s: unknown' % (package,))
diff --git a/doc/api.rst b/doc/api.rst
index 6ca5b6c2..5e0e6b1a 100644
--- a/doc/api.rst
+++ b/doc/api.rst
@@ -6,6 +6,7 @@
============
.. autosummary::
+ bob.devtools.log
bob.devtools.conda
bob.devtools.release
bob.devtools.changelog
@@ -14,6 +15,8 @@
Detailed Information
--------------------
+.. automodule:: bob.devtools.log
+
.. automodule:: bob.devtools.conda
.. automodule:: bob.devtools.release
--
GitLab