Move CLI's logging initialization into a dedicated module

conda_build/build.py

@@ -8,6 +8,7 @@
 
 import fnmatch
 import json
+import logging
 import os
 import random
 import re
@@ -94,6 +95,8 @@
 if TYPE_CHECKING:
     from typing import Any, Iterable
 
+log = logging.getLogger(__name__)
+
 if "bsd" in sys.platform:
     shell_path = "/bin/sh"
 elif utils.on_win:
@@ -924,7 +927,6 @@ def copy_test_source_files(m, destination):
                             clobber=True,
                         )
                     except OSError as e:
-                        log = utils.get_logger(__name__)
                         log.warning(
                             f"Failed to copy {f} into test files.  Error was: {str(e)}"
                         )
@@ -1304,7 +1306,6 @@ def write_about_json(m):
         extra = m.get_section("extra")
         # Add burn-in information to extra
         if m.config.extra_meta:
-            log = utils.get_logger(__name__)
             log.info(
                 "Adding the following extra-meta data to about.json: %s",
                 m.config.extra_meta,
@@ -1611,7 +1612,6 @@ def post_process_files(m: MetaData, initial_prefix_files):
         if not os.path.exists(os.path.join(host_prefix, f)):
             missing.append(f)
     if len(missing):
-        log = utils.get_logger(__name__)
         log.warning(
             f"The install/build script(s) for {package_name} deleted the following "
             f"files (from dependencies) from the prefix:\n{missing}\n"
@@ -1683,7 +1683,6 @@ def bundle_conda(
     new_prefix_files: set[str] = set(),
     **kw,
 ):
-    log = utils.get_logger(__name__)
     log.info("Packaging %s", metadata.dist())
     get_all_replacements(metadata.config)
     files = output.get("files", [])
@@ -2176,7 +2175,6 @@ def _write_activation_text(script_path, m):
         elif os.path.splitext(script_path)[1].lower() == ".sh":
             _write_sh_activation_text(fh, m)
         else:
-            log = utils.get_logger(__name__)
             log.warning(
                 f"not adding activation to {script_path} - I don't know how to do so for "
                 "this file type"
@@ -2317,7 +2315,6 @@ def build(
         print(utils.get_skip_message(m))
         return default_return
 
-    log = utils.get_logger(__name__)
     host_precs = []
     build_precs = []
     output_metas = []
@@ -2918,8 +2915,6 @@ def _construct_metadata_for_test_from_package(package, config):
     #    This is still necessary for computing the hash correctly though
     config.variant = hash_input
 
-    log = utils.get_logger(__name__)
-
     # get absolute file location
     local_pkg_location = os.path.normpath(os.path.abspath(os.path.dirname(package)))
 
@@ -3125,7 +3120,6 @@ def _write_test_run_script(
     shell_files,
     trace,
 ):
-    log = utils.get_logger(__name__)
     with open(test_run_script, "w") as tf:
         tf.write(
             '{source} "{test_env_script}"\n'.format(
@@ -3284,7 +3278,6 @@ def test(
     :param m: Package's metadata.
     :type m: Metadata
     """
-    log = utils.get_logger(__name__)
     # we want to know if we're dealing with package input.  If so, we can move the input on success.
     hash_input = {}
 
@@ -3568,7 +3561,6 @@ def tests_failed(
     dest = join(broken_dir, os.path.basename(pkg))
 
     if move_broken:
-        log = utils.get_logger(__name__)
         try:
             shutil.move(pkg, dest)
             log.warning(
@@ -3719,7 +3711,6 @@ def build_tree(
                                     )
                                 ]
                             )
-                            log = utils.get_logger(__name__)
                             # downstreams can be a dict, for adding capability for worker labels
                             if hasattr(downstreams, "keys"):
                                 downstreams = list(downstreams.keys())
@@ -4059,11 +4050,11 @@ def handle_pypi_upload(wheels, config):
             try:
                 utils.check_call_env(args + [f])
             except:
-                utils.get_logger(__name__).warning(
+                log.warning(
                     "wheel upload failed - is twine installed?"
                     "  Is this package registered?"
                 )
-                utils.get_logger(__name__).warning(f"Wheel file left in {f}")
+                log.warning(f"Wheel file left in {f}")
 
     else:
         print(f"anaconda_upload is not set.  Not uploading wheels: {wheels}")

conda_build/cli/logging.py

@@ -0,0 +1,94 @@
+# Copyright (C) 2014 Anaconda, Inc
+# SPDX-License-Identifier: BSD-3-Clause
+from __future__ import annotations
+
+import logging
+import logging.config
+import os
+import os.path
+import sys
+from functools import lru_cache
+from pathlib import Path
+from typing import TYPE_CHECKING
+
+from conda.base.context import context
+from yaml import safe_load
+
+if TYPE_CHECKING:
+    from logging import LogRecord
+
+
+# https://stackoverflow.com/a/31459386/1170370
+class LessThanFilter(logging.Filter):
+    def __init__(self, exclusive_maximum: int, name: str = "") -> None:
+        super().__init__(name)
+        self.max_level = exclusive_maximum
+
+    def filter(self, record: LogRecord) -> bool:
+        return record.levelno < self.max_level
+
+
+class GreaterThanFilter(logging.Filter):
+    def __init__(self, exclusive_minimum: int, name: str = "") -> None:
+        super().__init__(name)
+        self.min_level = exclusive_minimum
+
+    def filter(self, record: LogRecord) -> bool:
+        return record.levelno > self.min_level
+
+
+class DuplicateFilter(logging.Filter):
+    msgs: set[str] = set()
+
+    def filter(self, record: LogRecord) -> bool:
+        try:
+            return record.msg not in self.msgs
+        finally:
+            self.msgs.add(record.msg)
+
+
+@lru_cache
+def init_logging() -> None:
+    """
+    Default initialization of logging for conda-build CLI.
+
+    When using conda-build as a CLI tool (not as a library) we wish to limit logging to
+    avoid duplication and to otherwise offer some default behavior.
+
+    This is a onetime initialization that should be called at the start of CLI execution.
+    """
+    # undo conda messing with the root logger
+    logging.getLogger(None).setLevel(logging.WARNING)
+
+    # load the logging configuration from the config file
+    config_file = context.conda_build.get("log_config_file")
+    if config_file:
+        config_file = Path(os.path.expandvars(config_file)).expanduser().resolve()
+        logging.config.dictConfig(safe_load(config_file.read_text()))
+
+    log = logging.getLogger("conda_build")
+
+    # historically conda_build has defaulted the logging to INFO and so all of the
+    # log.info is viewed as default output, until we convert all of the existing
+    # log.info to standard print statements we will need to continue defaulting to INFO
+    if log.level == logging.NOTSET:
+        log.setLevel(logging.INFO)
+
+    # we don't want propagation to the root logger in CLI, but we do want it in tests
+    # this is a pytest limitation: https://github.com/pytest-dev/pytest/issues/3697
+    log.propagate = "PYTEST_CURRENT_TEST" in os.environ
+
+    if not log.handlers:
+        # only add our handlers when none are added via logging.config
+
+        # filter DEBUG/INFO messages to stdout
+        log.addHandler(stdout := logging.StreamHandler(sys.stdout))
+        stdout.addFilter(LessThanFilter(logging.WARNING))
+        stdout.addFilter(DuplicateFilter())  # avoid duplicate messages
+        stdout.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))
+
+        # filter WARNING/ERROR/CRITICAL messages to stderr
+        log.addHandler(stderr := logging.StreamHandler(sys.stderr))
+        stderr.addFilter(GreaterThanFilter(logging.INFO))
+        stderr.addFilter(DuplicateFilter())  # avoid duplicate messages
+        stderr.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))

conda_build/cli/main_build.py

@@ -24,6 +24,7 @@
 )
 from ..utils import LoggingContext
 from .actions import KeyValueAction
+from .logging import init_logging
 from .main_render import get_render_parser
 
 try:
@@ -36,6 +37,8 @@
     from argparse import ArgumentParser, Namespace
     from typing import Sequence
 
+log = logging.getLogger(__name__)
+
 
 def parse_args(args: Sequence[str] | None) -> tuple[ArgumentParser, Namespace]:
     parser = get_render_parser()
@@ -531,6 +534,8 @@ def check_action(recipe, config):
 
 
 def execute(args: Sequence[str] | None = None) -> int:
+    init_logging()
+
     _, parsed = parse_args(args)
     context.__init__(argparse_args=parsed)
 

conda_build/cli/main_convert.py

@@ -9,12 +9,13 @@
 from conda.base.context import context
 
 from .. import api
+from .logging import init_logging
 
 if TYPE_CHECKING:
     from argparse import ArgumentParser, Namespace
     from typing import Sequence
 
-logging.basicConfig(level=logging.INFO)
+log = logging.getLogger(__name__)
 
 epilog = """
 
@@ -127,6 +128,8 @@ def parse_args(args: Sequence[str] | None) -> tuple[ArgumentParser, Namespace]:
 
 
 def execute(args: Sequence[str] | None = None) -> int:
+    init_logging()
+
     _, parsed = parse_args(args)
     context.__init__(argparse_args=parsed)
 

conda_build/cli/main_debug.py

@@ -11,13 +11,14 @@
 from .. import api
 from ..utils import on_win
 from . import validators as valid
+from .logging import init_logging
 from .main_render import get_render_parser
 
 if TYPE_CHECKING:
     from argparse import ArgumentParser
     from typing import Sequence
 
-logging.basicConfig(level=logging.INFO)
+log = logging.getLogger(__name__)
 
 
 def get_parser() -> ArgumentParser:
@@ -94,6 +95,8 @@ def get_parser() -> ArgumentParser:
 
 
 def execute(args: Sequence[str] | None = None) -> int:
+    init_logging()
+
     parser = get_parser()
     parsed = parser.parse_args(args)
     context.__init__(argparse_args=parsed)

conda_build/cli/main_develop.py

@@ -8,6 +8,7 @@
 from conda.base.context import context
 
 from .. import api
+from .logging import init_logging
 
 try:
     from conda.cli.helpers import add_parser_prefix
@@ -19,7 +20,7 @@
     from argparse import ArgumentParser, Namespace
     from typing import Sequence
 
-logging.basicConfig(level=logging.INFO)
+log = logging.getLogger(__name__)
 
 
 def parse_args(args: Sequence[str] | None) -> tuple[ArgumentParser, Namespace]:
@@ -87,6 +88,8 @@ def parse_args(args: Sequence[str] | None) -> tuple[ArgumentParser, Namespace]:
 
 
 def execute(args: Sequence[str] | None = None) -> int:
+    init_logging()
+
     _, parsed = parse_args(args)
     context.__init__(argparse_args=parsed)
 

conda_build/cli/main_inspect.py

@@ -11,6 +11,7 @@
 from conda.base.context import context
 
 from .. import api
+from .logging import init_logging
 
 try:
     from conda.cli.helpers import add_parser_prefix
@@ -22,7 +23,7 @@
     from argparse import ArgumentParser, Namespace
     from typing import Sequence
 
-logging.basicConfig(level=logging.INFO)
+log = logging.getLogger(__name__)
 
 
 def parse_args(args: Sequence[str] | None) -> tuple[ArgumentParser, Namespace]:
@@ -195,6 +196,8 @@ def parse_args(args: Sequence[str] | None) -> tuple[ArgumentParser, Namespace]:
 
 
 def execute(args: Sequence[str] | None = None) -> int:
+    init_logging()
+
     parser, parsed = parse_args(args)
     context.__init__(argparse_args=parsed)
 

conda_build/cli/main_metapackage.py

@@ -9,6 +9,7 @@
 from conda.base.context import context
 
 from .. import api
+from .logging import init_logging
 
 try:
     from conda.cli.helpers import add_parser_channels
@@ -20,7 +21,7 @@
     from argparse import ArgumentParser, Namespace
     from typing import Sequence
 
-logging.basicConfig(level=logging.INFO)
+log = logging.getLogger(__name__)
 
 
 def parse_args(args: Sequence[str] | None) -> tuple[ArgumentParser, Namespace]:
@@ -121,6 +122,8 @@ def parse_args(args: Sequence[str] | None) -> tuple[ArgumentParser, Namespace]:
 
 
 def execute(args: Sequence[str] | None = None) -> int:
+    init_logging()
+
     _, parsed = parse_args(args)
     context.__init__(argparse_args=parsed)
 

conda_build/cli/main_render.py

@@ -15,6 +15,7 @@
 from ..config import get_channel_urls, get_or_merge_config
 from ..utils import LoggingContext
 from ..variants import get_package_variants, set_language_env_vars
+from .logging import init_logging
 
 try:
     from conda.cli.helpers import add_parser_channels
@@ -201,6 +202,8 @@ def parse_args(args: Sequence[str] | None) -> tuple[ArgumentParser, Namespace]:
 
 
 def execute(args: Sequence[str] | None = None) -> int:
+    init_logging()
+
     _, parsed = parse_args(args)
     context.__init__(argparse_args=parsed)