Introduce logging modes

beets/__init__.py

@@ -13,12 +13,18 @@
 # included in all copies or substantial portions of the Software.
 
 
+from __future__ import annotations
+
 from sys import stderr
+from typing import TYPE_CHECKING
 
 import confuse
 
 from .util.deprecation import deprecate_imports
 
+if TYPE_CHECKING:
+    from .logging import Logger
+
 __version__ = "2.12.0"
 __author__ = "Adrian Sampson <adrian@radbox.org>"
 
@@ -46,5 +52,15 @@ def read(self, user: bool = True, defaults: bool = True) -> None:
         except confuse.ConfigReadError as err:
             stderr.write(f"configuration `import` failed: {err.reason}")
 
+    def log_sources(self, log: Logger) -> None:
+        """Log all configuration sources in priority order."""
+
+        log.debug("configuration sources (highest → lowest priority):")
+        # skip first source as it is always the root source/empty
+        for source in self.sources[1:]:
+            log.debug(
+                "{} {}", type(source).__name__, getattr(source, "filename", "")
+            )
+
 
 config = IncludeLazyConfig("beets", __name__)

beets/ui/__init__.py

@@ -56,13 +56,6 @@
 
 
 log = logging.getLogger("beets")
-if not log.handlers:
-    handler = logging.StreamHandler()
-    handler.setFormatter(
-        logging.LegacyFormatter("%(legacy_prefix)s%(message)s")
-    )
-    log.addHandler(handler)
-log.propagate = False  # Don't propagate to root handler.
 
 
 # Encoding utilities.
@@ -767,14 +760,11 @@ def parse_subcommand(self, args):
 # The main entry point and bootstrapping.
 
 
-def _setup(
-    options: optparse.Values,
-) -> tuple[list[Subcommand], library.Library]:
+def _setup() -> tuple[list[Subcommand], library.Library]:
     """Prepare and global state and updates it with command line options.
 
     Returns a list of subcommands, a list of plugins, and a library instance.
     """
-    config = _configure(options)
 
     plugins.load_plugins()
 
@@ -790,43 +780,6 @@ def _setup(
     return subcommands, lib
 
 
-def _configure(options):
-    """Amend the global configuration object with command line options."""
-    # Add any additional config files specified with --config. This
-    # special handling lets specified plugins get loaded before we
-    # finish parsing the command line.
-    if getattr(options, "config", None) is not None:
-        overlay_path = options.config
-        del options.config
-        config.set_file(overlay_path)
-    else:
-        overlay_path = None
-    config.set_args(options)
-
-    # Configure the logger.
-    if config["verbose"].get(int):
-        log.set_global_level(logging.DEBUG)
-    else:
-        log.set_global_level(logging.INFO)
-
-    if overlay_path:
-        log.debug(
-            "overlaying configuration: {}", util.displayable_path(overlay_path)
-        )
-
-    config_path = config.user_config_path()
-    if os.path.isfile(config_path):
-        log.debug("user configuration: {}", util.displayable_path(config_path))
-    else:
-        log.debug(
-            "no user configuration found at {}",
-            util.displayable_path(config_path),
-        )
-
-    log.debug("data directory: {}", util.displayable_path(config.config_dir()))
-    return config
-
-
 def _ensure_db_directory_exists(path):
     if path == b":memory:":  # in memory db
         return
@@ -929,9 +882,11 @@ def parse_csl_callback(
 
     options, subargs = parser.parse_global_options(args)
 
-    # Special case for the `config --edit` command: bypass _setup so
-    # that an invalid configuration does not prevent the editor from
-    # starting.
+    # Defer config errors such that logging is available early for error reporting
+    # also allows `config --edit` command to bypass on config errors
+    deferred_error = _bootstrap_config(options)
+    _bootstrap_logging()
+
     if (
         subargs
         and subargs[0] == "config"
@@ -941,7 +896,18 @@ def parse_csl_callback(
 
         return config_edit(options)
 
-    subcommands, lib = _setup(options)
+    if "AppData\\Local\\Microsoft\\WindowsApps" in sys.exec_prefix:
+        raise UserError(
+            "beets is unable to use the Microsoft Store version of "
+            "Python. Please install Python from https://python.org.\n"
+            "More details can be found here "
+            "https://beets.readthedocs.io/en/stable/guides/main.html"
+        )
+
+    if deferred_error:
+        raise deferred_error
+
+    subcommands, lib = _setup()
     parser.add_subcommand(*subcommands)
 
     subcommand, suboptions, subargs = parser.parse_subcommand(subargs)
@@ -952,18 +918,57 @@ def parse_csl_callback(
     return None
 
 
+def _bootstrap_config(options: optparse.Values) -> confuse.ConfigError | None:
+    """Apply CLI to config, initialize logging, return error as value if any."""
+
+    deferred_error: confuse.ConfigError | None = None
+    try:
+        # Explicit read() so we own error handling (a broken user config file would
+        # otherwise surface on the first implicit config access e.g. config["verbose"].
+        # It also ensures confuse's source list is populated before set_file() adds the
+        #  --config overlay.
+        config.read()
+        if overlay_path := getattr(options, "config", None):
+            config.set_file(overlay_path)
+    except confuse.ConfigError as e:
+        deferred_error = e
+        # Ensure defaults are loaded even when user config is broken,
+        # so that logging and other subsystems can read basic settings.
+        config.read(user=False, defaults=True)
+
+    # Even if the earlier config loading fails we seperatly try to set the
+    # cli options
+    try:
+        config.set_args(options)
+    except confuse.ConfigError as e:
+        deferred_error = e
+
+    return deferred_error
+
+
+def _bootstrap_logging():
+    if not log.handlers:
+        handler = logging.StreamHandler()
+        handler.setFormatter(
+            logging.LegacyFormatter("%(legacy_prefix)s%(message)s")
+        )
+        log.addHandler(handler)
+
+    # Verbosity level set via cli --verbose.
+    if config["verbose"].get(int):
+        log.set_global_level(logging.DEBUG)
+    else:
+        log.set_global_level(logging.INFO)
+
+    # List configuration sources for user convenience.
+    config.log_sources(log)
+    log.debug("data directory: {}", util.displayable_path(config.config_dir()))
+
+
 def main(args: list[str] | None = None) -> None:
     """Run the main command-line interface for beets. Includes top-level
     exception handlers that print friendly error messages.
     """
-    if "AppData\\Local\\Microsoft\\WindowsApps" in sys.exec_prefix:
-        log.error(
-            "error: beets is unable to use the Microsoft Store version of "
-            "Python. Please install Python from https://python.org.\n"
-            "error: More details can be found here "
-            "https://beets.readthedocs.io/en/stable/guides/main.html"
-        )
-        sys.exit(1)
     try:
         _raw_main(args)
     except UserError as exc:

docs/reference/index.rst

@@ -12,3 +12,4 @@ started with beets as a new user, though, you may want to read the
     config
     pathformat
     query
+    logging

docs/reference/logging.rst

@@ -0,0 +1,176 @@
+Logging
+=======
+
+Beets implements a flexible logging solution and ships multiple built-in modes.
+You can select a mode from the command line for quick control, or define and
+customize modes in the configuration file for more advanced setups.
+
+Use the ``--logging <mode>`` option to select a logging mode for a single
+invocation of any beets command. For example, to run the import command in debug
+mode, you could do:
+
+.. code-block:: console
+
+    beets --logging debug import music/
+
+.. note::
+
+    The command-line option overrides any logging mode configured in the
+    configuration file.
+
+If you want to persist a logging mode across multiple invocations of beets, you
+can define a mode in the configuration file. For example, to set the default
+logging mode to ``debug``, you could add the following to your configuration
+file:
+
+.. code-block:: yaml
+    :caption: config.yaml
+
+    logging: debug
+
+.. note::
+
+    Invalid logging modes will be ignored, and beets will fall back to the
+    default mode.
+
+Build-in modes
+--------------
+
+Beets ships with several built-in logging modes. The following table summarizes
+the available modes and their characteristics:
+
+.. conf:: legacy
+
+    The default mode for ``beets<v3.0.0``. Logs messages as plain text with a simple prefix indicating a plugin name.
+
+
+    .. code-block:: console
+
+        <plugin>: <message>
+        TODO Add a real output
+
+.. conf:: verbose
+
+    The default logging mode for ``beets>=v3.0.0``.
+
+    This mode explains what beets is doing in a more explicit way than
+    ``legacy``, including key decisions such as matching, tagging, and
+    file operations, without exposing full internal debug information.
+
+    .. code-block:: console
+
+        [<level:Info+>] <logger>: <message>
+        TODO Add a real output
+
+
+    This mode aims to be the recommended default for users on beets 3.0+ as it improves transparency while keeping output readable.
+
+.. conf:: quiet
+
+    Suppresses informational output and only displays warnings and errors.
+
+    This mode is useful when running beets in scripts or when you want to minimize console output while still being notified of important issues.
+
+    .. code-block:: console
+
+        [<level:Warning+>] <logger>: <message>
+        TODO Add a real output
+
+.. conf:: debug
+
+    Enables verbose diagnostic logging for both core functionality and plugins.
+
+    This mode includes timestamps, log levels, and logger names, making it
+    useful for debugging and development.
+
+    .. code-block:: console
+
+        <time> [<level:Debug+>] <logger>: <message> (<filename>:<line number>)
+        TODO Add a real output
+
+    Be warned, this mode may produce a large volume of output, especially when
+    plugins with extensive logging are enabled.
+
+Custom modes
+------------
+
+While the built-in modes should cover most use cases, having more control over
+the logging configuration can be useful. Beets allows you to define custom
+logging modes in the configuration file.
+
+Custom modes are defined using Python’s standard logging configuration
+dictionary schema. This gives you full access to handlers, formatters, filters,
+and logger configuration options as described in the `Python logging
+documentation
+<https://docs.python.org/3/library/logging.config.html#logging-config-dictschema>`_.
+
+.. code-block:: yaml
+    :caption: config.yaml: Example custom logging mode
+
+    loggging: my_mode
+
+    logging_modes:
+        my_mode:
+            version: 1
+            formatters:
+                detailed:
+                    format: "[%(levelname)s] %(name)s: %(message)s"
+
+            handlers:
+                console:
+                    class: logging.StreamHandler
+                    level: DEBUG
+                    formatter: detailed
+                    stream: ext://sys.stdout
+
+            root:
+                level: DEBUG
+                handlers: [console]
+
+What about the current ``print`` calls?
+---------------------------------------
+
+Will remove this section or rewrite it (just for discussion right now).
+
+``print`` statements should only be used in the ``ui`` layer and are not part of
+the logging system.
+
+Unlike log messages, output from the UI layer is always shown regardless of the
+active logging mode. This ensures that essential user-facing interaction is
+never hidden or filtered by logging configuration.
+
+The UI layer is intended for direct user communication, such as:
+
+- prompts and confirmations
+- interactive questions
+- critical status messages that require immediate attention
+- explicit user-facing feedback during command execution
+
+In other words, the UI layer represents the *communication interface* of beets,
+while the logging system represents *diagnostic and operational telemetry*.
+
+What to do with the ``-v`` options?
+-----------------------------------
+
+Will remove this section or rewrite it (just for discussion right now).
+
+We still have the ``-v`` option to enable verbosity but it is currently a bit
+inconsistent. What I would propose is the follow
+
+.. list-table::
+    :header-rows: 1
+    :widths: 15 85
+
+    - - Flag
+      - Effect
+    - - (none)
+      - Uses the default level defined by the active logging mode (e.g. ``INFO``
+        in ``legacy``).
+    - - ``-v``
+      - Increases verbosity to ``INFO`` if the current level is lower. Has no
+        effect if the mode is already more verbose.
+    - - ``-vv``
+      - Forces ``DEBUG`` level output across the application (``beets`` logger)
+    - - ``-vvv``
+      - Enables maximum verbosity, including extended diagnostic output from
+        (all loggers).