diff --git a/README.md b/README.md index 238c5ab0e..e4f39463a 100644 --- a/README.md +++ b/README.md @@ -109,7 +109,7 @@ pypi: https://pypi.org/project/envoy.base.checker #### [envoy.base.runner](envoy.base.runner) -version: 0.0.5.dev0 +version: 0.0.5 pypi: https://pypi.org/project/envoy.base.runner diff --git a/envoy.base.runner/VERSION b/envoy.base.runner/VERSION index ccf3e968d..bbdeab622 100644 --- a/envoy.base.runner/VERSION +++ b/envoy.base.runner/VERSION @@ -1 +1 @@ -0.0.5-dev +0.0.5 diff --git a/envoy.base.runner/envoy/base/runner/__init__.py b/envoy.base.runner/envoy/base/runner/__init__.py index 8ea79c5c1..0226166ef 100644 --- a/envoy.base.runner/envoy/base/runner/__init__.py +++ b/envoy.base.runner/envoy/base/runner/__init__.py @@ -1,10 +1,9 @@ +from . import runner from .decorators import ( catches, cleansup) - from .abstract import AAsyncRunnerWithCommands - from .runner import ( AsyncRunner, BaseRunner, @@ -27,4 +26,5 @@ "cleansup", "ForkingAdapter", "ForkingRunner", - "Runner") + "Runner", + "runner") diff --git a/envoy.base.runner/envoy/base/runner/runner.py b/envoy.base.runner/envoy/base/runner/runner.py index c6752d3d8..04597e8bb 100644 --- a/envoy.base.runner/envoy/base/runner/runner.py +++ b/envoy.base.runner/envoy/base/runner/runner.py @@ -45,10 +45,29 @@ class BazelRunError(Exception): pass +class BaseLogFilter(logging.Filter): + + def __init__(self, app_logger: logging.Logger, *args, **kwargs) -> None: + self.app_logger = app_logger + + +class RootLogFilter(BaseLogFilter): + + def filter(self, record) -> bool: + return record.name != self.app_logger.name + + +class AppLogFilter(BaseLogFilter): + + def filter(self, record) -> bool: + return record.name == self.app_logger.name + + class BaseRunner: def __init__(self, *args): self._args = args + self.setup_logging() def __call__(self): return self.run() @@ -63,38 +82,36 @@ def extra_args(self) -> list: """Unparsed args.""" return self.parser.parse_known_args(self._args)[1] - @property - def log_field_styles(self): - return LOG_FIELD_STYLES - - @property - def log_fmt(self): - return LOG_FMT - - @property - def log_level_styles(self): - return LOG_LEVEL_STYLES - @cached_property def log(self) -> verboselogs.VerboseLogger: """Instantiated logger.""" - verboselogs.install() - logger = logging.getLogger(self.name) - logger.setLevel(self.log_level) + app_logger = verboselogs.VerboseLogger(self.name) coloredlogs.install( field_styles=self.log_field_styles, level_styles=self.log_level_styles, fmt=self.log_fmt, - level='DEBUG', - logger=logger, + level=self.verbosity, + logger=app_logger, isatty=True) - return logger + return app_logger + + @property + def log_field_styles(self): + return LOG_FIELD_STYLES + + @property + def log_fmt(self): + return LOG_FMT @cached_property def log_level(self) -> int: """Log level parsed from args.""" return dict(LOG_LEVELS)[self.args.log_level] + @property + def log_level_styles(self): + return LOG_LEVEL_STYLES + @property def name(self) -> str: """Name of the runner.""" @@ -111,6 +128,27 @@ def parser(self) -> argparse.ArgumentParser: def path(self) -> pathlib.Path: return pathlib.Path(".") + @property + def root_log_format(self) -> logging.Formatter: + return logging.Formatter("%(name)s: %(levelname)s %(message)s") + + @cached_property + def root_log_handler(self) -> logging.Handler: + """Instantiated logger.""" + root_handler = logging.StreamHandler() + root_handler.setLevel(self.log_level) + root_handler.addFilter(RootLogFilter(self.log)) + root_handler.setFormatter(self.root_log_format) + return root_handler + + @cached_property + def root_logger(self) -> logging.Logger: + """Instantiated logger.""" + root_logger = logging.getLogger() + root_logger.handlers[0].addFilter(AppLogFilter(self.log)) + root_logger.addHandler(self.root_log_handler) + return root_logger + @cached_property def stdout(self) -> logging.Logger: """Log to stdout.""" @@ -134,14 +172,10 @@ def tempdir(self) -> tempfile.TemporaryDirectory: "decorated with `@runner.cleansup`") return tempfile.TemporaryDirectory() - def add_arguments(self, parser: argparse.ArgumentParser) -> None: - """Override this method to add custom arguments to the arg parser.""" - parser.add_argument( - "--log-level", - "-l", - choices=[level[0] for level in LOG_LEVELS], - default="info", - help="Log level to display") + @cached_property + def verbosity(self) -> int: + """Log level parsed from args.""" + return dict(LOG_LEVELS)[self.args.verbosity] @property def _missing_cleanup(self) -> bool: @@ -152,6 +186,26 @@ def _missing_cleanup(self) -> bool: getattr(run_fun, "__wrapped__", object()), "__cleansup__", False)) + def add_arguments(self, parser: argparse.ArgumentParser) -> None: + """Override this method to add custom arguments to the arg parser.""" + parser.add_argument( + "--verbosity", + "-v", + choices=[level[0] for level in LOG_LEVELS], + default="info", + help="Application log level") + parser.add_argument( + "--log-level", + "-l", + choices=[level[0] for level in LOG_LEVELS], + default="warn", + help="Log level for non-application logs") + + def setup_logging(self): + logging.basicConfig(level=self.log_level) + self.root_logger.setLevel(self.log_level) + self.log.setLevel(self.verbosity) + def _cleanup_tempdir(self) -> None: if "tempdir" in self.__dict__: self.tempdir.cleanup() diff --git a/envoy.base.runner/tests/test_abstract.py b/envoy.base.runner/tests/test_abstract.py index 9f2ace424..c920b18b0 100644 --- a/envoy.base.runner/tests/test_abstract.py +++ b/envoy.base.runner/tests/test_abstract.py @@ -12,6 +12,9 @@ @abstracts.implementer(AAsyncRunnerWithCommands) class DummyAsyncRunnerWithCommands: + def __init__(self): + pass + @property def command(self): return super().command diff --git a/envoy.base.runner/tests/test_runner.py b/envoy.base.runner/tests/test_runner.py index cf85b7ef5..b5e52dd31 100644 --- a/envoy.base.runner/tests/test_runner.py +++ b/envoy.base.runner/tests/test_runner.py @@ -188,21 +188,32 @@ async def test_cleansup(async_fun, raises): == [(), {}]) -def test_base_runner_constructor(): - run = runner.BaseRunner("path1", "path2", "path3") +def test_base_runner_constructor(patches): + patched = patches( + "BaseRunner.setup_logging", + prefix="envoy.base.runner.runner") + + with patched as (m_setup, ): + run = runner.BaseRunner("path1", "path2", "path3") + + assert ( + m_setup.call_args + == [(), {}]) assert run._args == ("path1", "path2", "path3") assert run.log_field_styles == runner.runner.LOG_FIELD_STYLES assert run.log_level_styles == runner.runner.LOG_LEVEL_STYLES assert run.log_fmt == runner.runner.LOG_FMT -def test_base_runner_args(): - run = runner.BaseRunner("path1", "path2", "path3") - parser_mock = patch( - "envoy.base.runner.runner.BaseRunner.parser", - new_callable=PropertyMock) +def test_base_runner_args(patches): + patched = patches( + ("BaseRunner.parser", + dict(new_callable=PropertyMock)), + "BaseRunner.setup_logging", + prefix="envoy.base.runner.runner") - with parser_mock as m_parser: + with patched as (m_parser, m_setup): + run = runner.BaseRunner('path1', 'path2', 'path3') known_args = m_parser.return_value.parse_known_args assert ( run.args @@ -217,13 +228,15 @@ def test_base_runner_args(): assert "args" in run.__dict__ -def test_base_runner_extra_args(): - run = runner.BaseRunner("path1", "path2", "path3") - parser_mock = patch( - "envoy.base.runner.runner.BaseRunner.parser", - new_callable=PropertyMock) +def test_base_runner_extra_args(patches): + patched = patches( + ("BaseRunner.parser", + dict(new_callable=PropertyMock)), + "BaseRunner.setup_logging", + prefix="envoy.base.runner.runner") - with parser_mock as m_parser: + with patched as (m_parser, m_setup): + run = runner.BaseRunner('path1', 'path2', 'path3') known_args = m_parser.return_value.parse_known_args assert ( run.extra_args @@ -238,8 +251,8 @@ def test_base_runner_extra_args(): assert "extra_args" in run.__dict__ -def test_base_runner_log(patches): - run = runner.BaseRunner("path1", "path2", "path3") +def __test_base_runner_log(patches): + run = DummyRunner() patched = patches( "logging.getLogger", "coloredlogs", @@ -278,7 +291,7 @@ def test_base_runner_log(patches): def test_base_runner_log_level(patches): - run = runner.BaseRunner("path1", "path2", "path3") + run = DummyRunner() patched = patches( "dict", ("BaseRunner.args", dict(new_callable=PropertyMock)), @@ -302,25 +315,25 @@ def test_base_runner_name(): def test_base_runner_parser(patches): - run = runner.BaseRunner("path1", "path2", "path3") + run = DummyRunner() patched = patches( - "argparse.ArgumentParser", + "argparse", "BaseRunner.add_arguments", prefix="envoy.base.runner.runner") with patched as (m_parser, m_add_args): - assert run.parser == m_parser.return_value + assert run.parser == m_parser.ArgumentParser.return_value assert ( - list(m_parser.call_args) + list(m_parser.ArgumentParser.call_args) == [(), {"allow_abbrev": False}]) assert ( list(m_add_args.call_args) - == [(m_parser.return_value,), {}]) + == [(m_parser.ArgumentParser.return_value,), {}]) assert "parser" in run.__dict__ def test_base_runner_path(patches): - run = runner.BaseRunner("path1", "path2", "path3") + run = DummyRunner() patched = patches( "pathlib", prefix="envoy.base.runner.runner") @@ -334,8 +347,7 @@ def test_base_runner_path(patches): def test_base_runner_stdout(patches): - run = runner.BaseRunner("path1", "path2", "path3") - + run = DummyRunner() patched = patches( "logging", ("BaseRunner.log_level", dict(new_callable=PropertyMock)), @@ -366,7 +378,7 @@ def test_base_runner_stdout(patches): @pytest.mark.parametrize("missing", [True, False]) def test_base_runner_tempdir(patches, missing): - run = runner.BaseRunner() + run = DummyRunner() patched = patches( "tempfile", ("BaseRunner.log", dict(new_callable=PropertyMock)), @@ -391,18 +403,72 @@ def test_base_runner_tempdir(patches, missing): assert "tempdir" in run.__dict__ +def test_base_runner_verbosity(patches): + run = DummyRunner() + patched = patches( + "dict", + ("BaseRunner.args", dict(new_callable=PropertyMock)), + prefix="envoy.base.runner.runner") + with patched as (m_dict, m_args): + assert run.verbosity == m_dict.return_value.__getitem__.return_value + + assert ( + list(m_dict.call_args) + == [(runner.runner.LOG_LEVELS, ), {}]) + assert ( + list(m_dict.return_value.__getitem__.call_args) + == [(m_args.return_value.verbosity,), {}]) + assert "verbosity" in run.__dict__ + + def test_base_runner_add_arguments(): - run = runner.BaseRunner("path1", "path2", "path3") + run = DummyRunner() parser = MagicMock() assert run.add_arguments(parser) is None assert ( list(list(c) for c in parser.add_argument.call_args_list) - == [[('--log-level', '-l'), + == [[('--verbosity', + '-v'), + {'choices': ['debug', + 'info', + 'warn', + 'error'], + 'default': 'info', + 'help': 'Application log level'}], + [('--log-level', '-l'), {'choices': ['debug', 'info', 'warn', 'error'], - 'default': 'info', 'help': 'Log level to display'}], - ]) + 'default': 'warn', + 'help': 'Log level for non-application logs'}]]) + + +def test_runner_setup_logging(patches): + run = DummyRunner() + patched = patches( + "logging", + ("BaseRunner.log", + dict(new_callable=PropertyMock)), + ("BaseRunner.log_level", + dict(new_callable=PropertyMock)), + ("BaseRunner.root_logger", + dict(new_callable=PropertyMock)), + ("BaseRunner.verbosity", + dict(new_callable=PropertyMock)), + prefix="envoy.base.runner.runner") + + with patched as (m_logging, m_log, m_level, m_root, m_verb): + assert not run.setup_logging() + + assert ( + m_logging.basicConfig.call_args + == [(), dict(level=m_level.return_value)]) + assert ( + m_root.return_value.setLevel.call_args + == [(m_level.return_value, ), {}]) + assert ( + m_log.return_value.setLevel.call_args + == [(m_verb.return_value, ), {}]) @pytest.mark.parametrize("has_fun", [True, False]) @@ -412,7 +478,7 @@ def test_base_runner__missing_cleanup(has_fun, is_wrapped, cleansup): def _runner_factory(): if not has_fun: - return runner.BaseRunner() + return DummyRunner() class _Wrap: if cleansup: @@ -422,10 +488,10 @@ class _Wrapper: if is_wrapped: __wrapped__ = _Wrap() - class DummyRunner(runner.BaseRunner): + class DummyRunner2(DummyRunner): run = _Wrapper() - return DummyRunner() + return DummyRunner2() run = _runner_factory() @@ -438,7 +504,7 @@ class DummyRunner(runner.BaseRunner): @pytest.mark.parametrize("cached", [True, False]) def test_base_runner__cleanup_tempdir(patches, cached): - run = runner.BaseRunner() + run = DummyRunner() patched = patches( ("BaseRunner.tempdir", dict(new_callable=PropertyMock)), prefix="envoy.base.runner.runner") @@ -475,12 +541,13 @@ def test_runner_constructor(patches): def test_runner_dunder_call(patches): - run = runner.Runner() patched = patches( "Runner.run", + "Runner.setup_logging", prefix="envoy.base.runner.runner") - with patched as (m_run, ): + with patched as (m_run, m_setup): + run = runner.Runner() assert run() == m_run.return_value assert ( @@ -489,12 +556,13 @@ def test_runner_dunder_call(patches): def test_runner_cleanup(patches): - run = runner.Runner() patched = patches( "Runner._cleanup_tempdir", + "Runner.setup_logging", prefix="envoy.base.runner.runner") - with patched as (m_temp, ): + with patched as (m_temp, m_setup): + run = runner.Runner() assert not run.cleanup() assert ( @@ -521,13 +589,17 @@ def test_async_runner_constructor(patches): @pytest.mark.parametrize("raises", [None, KeyboardInterrupt]) def test_async_runner_dunder_call(patches, raises): - run = runner.AsyncRunner() patched = patches( "asyncio", + ("AsyncRunner.log", dict(new_callable=MagicMock)), ("AsyncRunner.run", dict(new_callable=MagicMock)), + "AsyncRunner.setup_logging", prefix="envoy.base.runner.runner") - with patched as (m_asyncio, m_run): + # TODO: TEST LOG + + with patched as (m_asyncio, m_log, m_run, m_setup): + run = runner.AsyncRunner() if raises: m_run.side_effect = raises("DIE") assert ( @@ -549,12 +621,13 @@ def test_async_runner_dunder_call(patches, raises): @pytest.mark.asyncio async def test_async_runner_cleanup(patches): - run = runner.AsyncRunner() patched = patches( "AsyncRunner._cleanup_tempdir", + "AsyncRunner.setup_logging", prefix="envoy.base.runner.runner") - with patched as (m_temp, ): + with patched as (m_temp, m_setup): + run = runner.AsyncRunner() assert not await run.cleanup() assert ( @@ -718,12 +791,16 @@ def test_forkingadapter_subproc_run(patches, args, cwd, capture_output): # ForkingRunner tests -def test_forkingrunner_fork(): - run = runner.ForkingRunner("path1", "path2", "path3") - forking_mock = patch("envoy.base.runner.runner.ForkingAdapter") +def test_forkingrunner_fork(patches): + patched = patches( + "ForkingAdapter", + "ForkingRunner.setup_logging", + prefix="envoy.base.runner.runner") - with forking_mock as m_fork: + with patched as (m_fork, m_setup): + run = runner.ForkingRunner("path1", "path2", "path3") assert run.subproc_run == m_fork.return_value + assert ( list(m_fork.call_args) == [(run,), {}]) @@ -732,11 +809,14 @@ def test_forkingrunner_fork(): # BazelRunner tests -def test_bazelrunner_bazel(): - run = runner.BazelRunner("path1", "path2", "path3") - bazel_mock = patch("envoy.base.runner.runner.BazelAdapter") +def test_bazelrunner_bazel(patches): + patched = patches( + "BazelAdapter", + "BazelRunner.setup_logging", + prefix="envoy.base.runner.runner") - with bazel_mock as m_bazel: + with patched as (m_bazel, m_setup): + run = runner.BazelRunner("path1", "path2", "path3") assert run.bazel == m_bazel.return_value assert ( list(m_bazel.call_args)