Merge pull request #658 from lsst/tickets/DM-33809

DM-33809: Change how --log-level works

doc/changes/DM-33809.feature.rst

@@ -0,0 +1,4 @@
+The command-line tooling has changed how it sets the default logger when using ``--log-level``.
+Now only the default logger(s) (``lsst`` and the colon-separated values stored in the ``$DAF_BUTLER_ROOT_LOGGER``) will be affected by using ``--log-level`` without a specific logger name.
+By default only this default logger will be set to ``INFO`` log level and all other loggers will remain as ``WARNING``.
+Use ``--log-level '.=level'`` to change the root logger (this will not change the default logger level and so an additional call to ``--log-level DEBUG`` may be needed to turn on debugging for all loggers).

doc/lsst.daf.butler/index.rst

@@ -70,6 +70,7 @@ Butler Command-Line Reference
    :maxdepth: 1
 
    scripts/options-file.rst
+   scripts/logging.rst
    scripts/butler
 
 .. _lsst.daf.butler-dev:

doc/lsst.daf.butler/scripts/logging.rst

@@ -0,0 +1,35 @@
+.. _cli_logging_options:
+
+Controlling Log Output from Command-Line Tooling
+================================================
+
+Every command-line program has a standard set of options that control how logs are reported.
+These can be listed using ``butler --help`` and are available to all command-line programs that :ref:`use the Butler command-line infrastructure <daf_butler_cli-other_commands>`.
+The logging options must be given before any subcommand is specified.
+
+By default the ``lsst`` log hierarchy is set to ``INFO`` logging level and the python root logger is left at its default level of ``WARNING``.
+Additional loggers (and their descendants) can be treated the same as the default ``lsst`` logger by setting the ``$DAF_BUTLER_DEFAULT_LOGGER`` environment variable to a colon-separated list of logger names.
+
+The logging level can be changed by using the ``--log-level`` command line option.
+To change all the default loggers to ``DEBUG`` use ``--log-level DEBUG``.
+The help text will list all the supported level names.
+To change the logging level of the root python logger use either ``--log-level .=LEVEL`` (where ``LEVEL`` is the required level from the supported list).
+Since the default logger is always set to ``INFO``, in order to set all loggers to, say, ``DEBUG`` then both the default and root logger must be set explicitly: ``--log-level "=DEBUG" --log-level DEBUG``.
+
+This syntax demonstrates how to specify finer control of specific loggers.
+For example to turn on debug logging solely in Butler datastores use ``--log-level lsst.daf.butler.datastores=DEBUG``.
+The ``-log-level`` option can be given multiple times.
+
+As an example of how the log options can be combined:
+
+.. code-block:: bash
+
+    butler --log-level lsst.daf.butler=DEBUG --long-log --log-label MY_ID --log-file log.json
+
+These options will:
+
+* set the ``lsst`` logger to ``INFO`` and the butler logger to ``DEBUG``, leaving all non-lsst loggers at ``WARNING``;
+* generate formatted log messages that will use the long format that includes time stamps with every log message containing the special text ``MY_ID``;
+* create a log file containing a JSON representation of the log messages.
+
+The JSON output always includes every piece of information from the log record; the ``--long-log`` option has no effect on the content of the JSON file.

doc/lsst.daf.butler/writing-subcommands.rst

@@ -413,6 +413,8 @@ The settings for ``obs_base`` are like this:
 
     envPrepend(DAF_BUTLER_PLUGINS, $OBS_BASE_DIR/python/lsst/obs/base/cli/resources.yaml)
 
+.. _daf_butler_cli-other_commands:
+
 Writing Other Commands
 ======================
 

python/lsst/daf/butler/cli/cliLog.py

@@ -21,14 +21,15 @@
 
 import datetime
 import logging
-from typing import Dict, Optional, Tuple
+import os
+from typing import Dict, Optional, Set, Tuple
 
 try:
     import lsst.log as lsstLog
 except ModuleNotFoundError:
     lsstLog = None
 
-from lsst.utils.logging import VERBOSE
+from lsst.utils.logging import TRACE, VERBOSE
 
 from ..core.logging import ButlerMDC, JsonLogFormatter
 
@@ -86,6 +87,29 @@ class CliLog:
     """Any FileHandler classes attached to the root logger by this class
     that need to be closed on reset."""
 
+    @staticmethod
+    def root_loggers() -> Set[str]:
+        """Return the default root logger.
+
+        Returns
+        -------
+        log_name : `set` of `str`
+            The name(s) of the root logger(s) to use when the log level is
+            being set without a log name being specified.
+
+        Notes
+        -----
+        The default is ``lsst`` (which controls the butler infrastructure)
+        but additional loggers can be specified by setting the environment
+        variable ``DAF_BUTLER_ROOT_LOGGER``. This variable can contain
+        multiple default loggers separated by a ``:``.
+        """
+        log_names = set(["lsst"])
+        envvar = "DAF_BUTLER_ROOT_LOGGER"
+        if envvar in os.environ:
+            log_names |= set(os.environ[envvar].split(":"))
+        return log_names
+
     @classmethod
     def initLog(
         cls,
@@ -150,13 +174,13 @@ def initLog(
             defaultHandler.setFormatter(formatter)
 
             logging.basicConfig(
-                level=logging.INFO,
+                level=logging.WARNING,
                 force=True,
                 handlers=[defaultHandler],
             )
 
         else:
-            logging.basicConfig(level=logging.INFO, format=cls.pylog_normalFmt, style="{")
+            logging.basicConfig(level=logging.WARNING, format=cls.pylog_normalFmt, style="{")
 
         # Initialize root logger level.
         cls._setLogLevel(None, "INFO")
@@ -236,8 +260,13 @@ def setLogLevels(cls, logLevels):
         logLevels : `list` of `tuple`
             per-component logging levels, each item in the list is a tuple
             (component, level), `component` is a logger name or an empty string
-            or `None` for root logger, `level` is a logging level name, one of
-            CRITICAL, ERROR, WARNING, INFO, DEBUG (case insensitive).
+            or `None` for default root logger, `level` is a logging level name,
+            one of CRITICAL, ERROR, WARNING, INFO, DEBUG (case insensitive).
+
+        Notes
+        -----
+        The special name ``.`` can be used to set the Python root
+        logger.
         """
         if isinstance(logLevels, dict):
             logLevels = logLevels.items()
@@ -257,15 +286,25 @@ def _setLogLevel(cls, component, level):
         Parameters
         ----------
         component : `str` or None
-            The name of the log component or None for the root logger.
+            The name of the log component or None for the default logger.
+            The root logger can be specified either by an empty string or
+            with the special name ``.``.
         level : `str`
             A valid python logging level.
         """
-        cls._recordComponentSetting(component)
-        if lsstLog is not None:
-            lsstLogger = lsstLog.Log.getLogger(component or "")
-            lsstLogger.setLevel(cls._getLsstLogLevel(level))
-        logging.getLogger(component or None).setLevel(cls._getPyLogLevel(level))
+        components: Set[Optional[str]]
+        if component is None:
+            components = cls.root_loggers()
+        elif not component or component == ".":
+            components = {None}
+        else:
+            components = {component}
+        for component in components:
+            cls._recordComponentSetting(component)
+            if lsstLog is not None:
+                lsstLogger = lsstLog.Log.getLogger(component or "")
+                lsstLogger.setLevel(cls._getLsstLogLevel(level))
+            logging.getLogger(component or None).setLevel(cls._getPyLogLevel(level))
 
     @staticmethod
     def _getPyLogLevel(level):
@@ -283,6 +322,8 @@ def _getPyLogLevel(level):
         """
         if level == "VERBOSE":
             return VERBOSE
+        elif level == "TRACE":
+            return TRACE
         return getattr(logging, level, None)
 
     @staticmethod
@@ -306,13 +347,16 @@ def _getLsstLogLevel(level):
 
         Notes
         -----
-        ``VERBOSE`` logging is not supported by the LSST logger and so will
-        always be converted to ``INFO``.
+        ``VERBOSE`` and ``TRACE`` logging are not supported by the LSST logger.
+        ``VERBOSE`` will be converted to ``INFO`` and ``TRACE`` will be
+        converted to ``DEBUG``.
         """
         if lsstLog is None:
             return None
         if level == "VERBOSE":
             level = "INFO"
+        elif level == "TRACE":
+            level = "DEBUG"
         pylog_level = CliLog._getPyLogLevel(level)
         return lsstLog.LevelTranslator.logging2lsstLog(pylog_level)
 

python/lsst/daf/butler/cli/opt/options.py

@@ -25,6 +25,7 @@
 import click
 from lsst.daf.butler.registry import CollectionType
 
+from ..cliLog import CliLog
 from ..utils import MWOptionDecorator, MWPath, split_commas, split_kv, unwrap, yaml_presets
 
 
@@ -118,7 +119,7 @@ def makeCollectionTypes(context, param, value):
 datasets_option = MWOptionDecorator("--datasets")
 
 
-logLevelChoices = ["CRITICAL", "ERROR", "WARNING", "INFO", "VERBOSE", "DEBUG"]
+logLevelChoices = ["CRITICAL", "ERROR", "WARNING", "INFO", "VERBOSE", "DEBUG", "TRACE"]
 log_level_option = MWOptionDecorator(
     "--log-level",
     callback=partial(
@@ -127,8 +128,11 @@ def makeCollectionTypes(context, param, value):
         normalize=True,
         unseparated_okay=True,
         add_to_default=True,
+        default_key=None,  # No separator
     ),
-    help=f"The logging level. Supported levels are [{'|'.join(logLevelChoices)}]",
+    help=f"The logging level. Without an explicit logger name, will only affect the default root loggers "
+    f"({', '.join(CliLog.root_loggers())}). To modify the root logger use '.=LEVEL'. "
+    f"Supported levels are [{'|'.join(logLevelChoices)}]",
     is_eager=True,
     metavar="LEVEL|COMPONENT=LEVEL",
     multiple=True,

python/lsst/daf/butler/cli/utils.py

@@ -50,11 +50,6 @@
 typeStrAcceptsMultiple = "TEXT ..."
 typeStrAcceptsSingle = "TEXT"
 
-# For parameters that support key-value inputs, this defines the separator
-# for those inputs.
-split_kv_separator = "="
-
-
 # The standard help string for the --where option when it takes a WHERE clause.
 where_help = (
     "A string expression similar to a SQL WHERE clause. May involve any column of a "

python/lsst/daf/butler/script/configDump.py

@@ -50,5 +50,8 @@ def configDump(repo, subset, searchpath, outfile):
         try:
             config = config[subset]
         except KeyError:
-            raise KeyError(f"{subset} not found in config at {repo}")
-    config.dump(outfile)
+            raise KeyError(f"{subset} not found in config at {repo} (has {config.names()})")
+    if hasattr(config, "dump"):
+        config.dump(outfile)
+    else:
+        print(f"{subset}: {config}", file=outfile)