Logging

Colored verbosity option

Click Extra provides a pre-configured option which adds a --verbosity/-v flag to your CLI. It allow users of your CLI to set the log level of a logging.Logger instance.

Integrated extra option

This option is added by default to @extra_command and @extra_group:

from click_extra import extra_command, echo

@extra_command
def my_cli():
    echo("It works!")

See the default --verbosity/-v option in the help screen:

$ my-cli --help
Usage: my-cli [OPTIONS]

Options:
  --time / --no-time        Measure and print elapsed execution time.  [default:
                            no-time]
  --color, --ansi / --no-color, --no-ansi
                            Strip out all colors and all ANSI codes from output.
                            [default: color]
  -C, --config CONFIG_PATH  Location of the configuration file. Supports glob
                            pattern of local path and remote URL.  [default:
                            ~/.config/my-cli/*.{toml,yaml,yml,json,ini,xml}]
  --show-params             Show all CLI parameters, their provenance, defaults
                            and value, then exit.
  -v, --verbosity LEVEL     Either CRITICAL, ERROR, WARNING, INFO, DEBUG.
                            [default: WARNING]
  --version                 Show the version and exit.
  -h, --help                Show this message and exit.

Which can be invoked to display all the gory details of your CLI with the DEBUG level:

$ my-cli --verbosity DEBUG
debug: Set <Logger click_extra (DEBUG)> to DEBUG.
debug: Set <RootLogger root (DEBUG)> to DEBUG.
debug: Load configuration matching /home/runner/.config/my-cli/*.{toml,yaml,yml,json,ini,xml}
debug: Pattern is not an URL: search local file system.
debug: No configuration file found.
debug: Version string template variables:
debug: {module}         : <module 'click_extra.testing' from '/home/runner/work/click-extra/click-extra/click_extra/testing.py'>
debug: {module_name}    : click_extra.testing
debug: {module_file}    : /home/runner/work/click-extra/click-extra/click_extra/testing.py
debug: {module_version} : None
debug: {package_name}   : click_extra
debug: {package_version}: 4.11.6
debug: {exec_name}      : click_extra.testing
debug: {version}        : 4.11.6
debug: {prog_name}      : my-cli
debug: {env_info}       : {'username': '-', 'guid': 'e03a8c4696dd85487358953346fd51b', 'hostname': '-', 'hostfqdn': '-', 'uname': {'system': 'Linux', 'node': '-', 'release': '6.8.0-1017-azure', 'version': '#20-Ubuntu SMP Tue Oct 22 03:43:13 UTC 2024', 'machine': 'x86_64', 'processor': 'x86_64'}, 'linux_dist_name': '', 'linux_dist_version': '', 'cpu_count': 4, 'fs_encoding': 'utf-8', 'ulimit_soft': 65536, 'ulimit_hard': 65536, 'cwd': '-', 'umask': '0o2', 'python': {'argv': '-', 'bin': '-', 'version': '3.12.7 (main, Oct 1 2024, 15:18:31) [GCC 13.2.0]', 'compiler': 'GCC 13.2.0', 'build_date': 'Oct  1 2024 15:18:31', 'version_info': [3, 12, 7, 'final', 0], 'features': {'openssl': 'OpenSSL 3.0.13 30 Jan 2024', 'expat': 'expat_2.6.3', 'sqlite': '3.45.1', 'tkinter': '8.6', 'zlib': '1.3', 'unicode_wide': True, 'readline': True, '64bit': True, 'ipv6': True, 'threading': True, 'urandom': True}}, 'time_utc': '2024-11-23 07:04:29.538853', 'time_utc_offset': 0.0, '_eco_version': '1.1.0'}
It works!
debug: Reset <RootLogger root (DEBUG)> to WARNING.
debug: Reset <Logger click_extra (DEBUG)> to WARNING.

Standalone option

The verbosity option can be used independently of @extra_command, and you can attach it to a vanilla commands:

import logging
from click import command, echo
from click_extra import verbosity_option

@command
@verbosity_option
def vanilla_command():
    echo("It works!")
    logging.debug("We're printing stuff.")

$ vanilla-command --help
Usage: vanilla-command [OPTIONS]

Options:
  -v, --verbosity LEVEL  Either CRITICAL, ERROR, WARNING, INFO, DEBUG.
  --help                 Show this message and exit.

$ vanilla-command
It works!

$ vanilla-command --verbosity DEBUG
debug: Set <Logger click_extra (DEBUG)> to DEBUG.
debug: Set <RootLogger root (DEBUG)> to DEBUG.
It works!
debug: We're printing stuff.
debug: Reset <RootLogger root (DEBUG)> to WARNING.
debug: Reset <Logger click_extra (DEBUG)> to WARNING.

Tip

Note in the output above how the verbosity option is automatticcaly printing its own log level as a debug message.

Default logger

By default the --verbosity option is setting the log level of Python’s global root logger.

That way you can simply use the module helpers like logging.debug:

import logging
from click import command
from click_extra import verbosity_option

@command
@verbosity_option
def my_cli():
    # Print a messages for each level.
    logging.debug("We're printing stuff.")
    logging.info("This is a message.")
    logging.warning("Mad scientist at work!")
    logging.error("Does not compute.")
    logging.critical("Complete meltdown!")

Hint

By default, the root logger is preconfigured to:

• output to <stderr>,

• render log records with the %(levelname)s: %(message)s format,

• color the log level name in the %(levelname)s variable,

• default to the INFO level.

You can check these defaults by running the CLI without the --verbosity option:

$ my-cli
warning: Mad scientist at work!
error: Does not compute.
critical: Complete meltdown!

And then see how each level selectively print messages and renders with colors:

$ my-cli --verbosity CRITICAL
critical: Complete meltdown!

$ my-cli --verbosity ERROR
error: Does not compute.
critical: Complete meltdown!

$ my-cli --verbosity WARNING
warning: Mad scientist at work!
error: Does not compute.
critical: Complete meltdown!

$ my-cli --verbosity INFO
info: This is a message.
warning: Mad scientist at work!
error: Does not compute.
critical: Complete meltdown!

$ my-cli --verbosity DEBUG
debug: Set <Logger click_extra (DEBUG)> to DEBUG.
debug: Set <RootLogger root (DEBUG)> to DEBUG.
debug: We're printing stuff.
info: This is a message.
warning: Mad scientist at work!
error: Does not compute.
critical: Complete meltdown!
debug: Reset <RootLogger root (DEBUG)> to WARNING.
debug: Reset <Logger click_extra (DEBUG)> to WARNING.

Attention

Level propagation

Because the default logger is root, its level is by default propagated to all other loggers:

import logging
from click import command, echo
from click_extra import verbosity_option

@command
@verbosity_option
def multiple_loggers():
   # Print to default root logger.
   root_logger = logging.getLogger()
   root_logger.info("Default informative message")
   root_logger.debug("Default debug message")

   # Print to a random logger.
   random_logger = logging.getLogger("my_random_logger")
   random_logger.info("Random informative message")
   random_logger.debug("Random debug message")

   echo("It works!")

$ multiple-loggers
It works!

$ multiple-loggers --verbosity DEBUG
debug: Set <Logger click_extra (DEBUG)> to DEBUG.
debug: Set <RootLogger root (DEBUG)> to DEBUG.
info: Default informative message
debug: Default debug message
info: Random informative message
debug: Random debug message
It works!
debug: Reset <RootLogger root (DEBUG)> to WARNING.
debug: Reset <Logger click_extra (DEBUG)> to WARNING.

Custom logger

If you’d like to target another logger than the default root logger, you can pass your own logger’s ID to the option parameter:

import logging
from click import command, echo
from click_extra import extra_basic_config, verbosity_option

# Create a custom logger in the style of Click Extra, with our own format message.
extra_basic_config(
    logger_name="app_logger",
    format="{levelname} | {name} | {message}",
)

@command
@verbosity_option(default_logger="app_logger")
def awesome_app():
    echo("Awesome App started")
    logger = logging.getLogger("app_logger")
    logger.debug("Awesome App has started.")

You can now check that the --verbosity option influence the log level of your own app_logger global logger:

$ awesome-app
Awesome App started

$ awesome-app --verbosity DEBUG
debug: Set <Logger click_extra (DEBUG)> to DEBUG.
debug: Set <Logger app_logger (DEBUG)> to DEBUG.
Awesome App started
debug | app_logger | Awesome App has started.
debug: Awesome App has started.
debug: Reset <Logger app_logger (DEBUG)> to WARNING.
debug: Reset <Logger click_extra (DEBUG)> to WARNING.

You can also pass the default logger object to the option:

import logging
from click import command, echo
from click_extra import verbosity_option

my_app_logger = logging.getLogger("app_logger")

@command
@verbosity_option(default_logger=my_app_logger)
def awesome_app():
    echo("Awesome App started")
    logger = logging.getLogger("app_logger")
    logger.debug("Awesome App has started.")

$ awesome-app --verbosity DEBUG
debug: Set <Logger click_extra (DEBUG)> to DEBUG.
debug: Set <Logger app_logger (DEBUG)> to DEBUG.
Awesome App started
debug | app_logger | Awesome App has started.
debug: Awesome App has started.
debug: Reset <Logger app_logger (DEBUG)> to WARNING.
debug: Reset <Logger click_extra (DEBUG)> to WARNING.

Custom configuration

The Python standard library provides the logging.basicConfig function, which is a helper to simplify the configuration of loggers and covers most use cases.

Click Extra provides a similar helper, click_extra.logging.extra_basic_config.

Todo

Write detailed documentation of extra_basic_config().

Get verbosity level

You can get the name of the current verbosity level from the context or the logger itself:

import logging
from click_extra import command, echo, pass_context, verbosity_option

@command
@verbosity_option
@pass_context
def vanilla_command(ctx):
    level_from_context = ctx.meta["click_extra.verbosity"]
    echo(f"Level from context: {level_from_context}")

    level_from_logger = logging._levelToName[logging.getLogger().getEffectiveLevel()]
    echo(f"Level from logger: {level_from_logger}")

$ vanilla-command --verbosity DEBUG
debug: Set <Logger click_extra (DEBUG)> to DEBUG.
debug: Set <RootLogger root (DEBUG)> to DEBUG.
Level from context: DEBUG
Level from logger: DEBUG
debug: Reset <RootLogger root (DEBUG)> to WARNING.
debug: Reset <Logger click_extra (DEBUG)> to WARNING.

Internal click_extra logger

Todo

Write docs!

click_extra.logging API

        classDiagram
  ExtraOption <|-- VerbosityOption
  Formatter <|-- ExtraLogFormatter
  Handler <|-- ExtraLogHandler
    

Logging utilities.

click_extra.logging.LOG_LEVELS: dict[str, int] = {'CRITICAL': 50, 'DEBUG': 10, 'ERROR': 40, 'INFO': 20, 'WARNING': 30}

Mapping of canonical log level names to their IDs.

Sorted from lowest to highest verbosity.

Are ignored:

• NOTSET, which is considered internal

• WARN, which is obsolete

• FATAL, which shouldn’t be used and replaced by CRITICAL

click_extra.logging.DEFAULT_LEVEL_NAME: str = 'WARNING'

WARNING is the default level we expect any loggers to starts their lives at.

WARNING has been chosen as it is the level at which the default Python’s global root logger is set up.

This value is also used as the default level of the --verbosity option below.

class click_extra.logging.THandler

Custom types to be used in type hints below.

alias of TypeVar(‘THandler’, bound=Handler)

class click_extra.logging.ExtraLogHandler(level=0)

Bases: Handler

A handler to output logs to console’s <stderr>.

Initializes the instance - basically setting the formatter to None and the filter list to empty.

emit(record)

Use click.echo to print to <stderr> and supports colors.

Return type:

None

class click_extra.logging.ExtraLogFormatter(fmt=None, datefmt=None, style='%', validate=True, *, defaults=None)

Bases: Formatter

Initialize the formatter with specified format strings.

Initialize the formatter either with the specified format string, or a default as described above. Allow for specialized date formatting with the optional datefmt argument. If datefmt is omitted, you get an ISO8601-like (or RFC 3339-like) format.

Use a style parameter of ‘%’, ‘{’ or ‘$’ to specify that you want to use one of %-formatting, str.format() ({}) formatting or string.Template formatting in your format string.

Changed in version 3.2: Added the style parameter.

formatMessage(record)

Colorize the record’s log level name before calling the strandard formatter.

Return type:

str

click_extra.logging.extra_basic_config(logger_name=None, format='{levelname}: {message}', datefmt=None, style='{', level=None, handlers=None, force=True, handler_class=<class 'click_extra.logging.ExtraLogHandler'>, formatter_class=<class 'click_extra.logging.ExtraLogFormatter'>)

Setup and configure a logger.

Reimplements logging.basicConfig, but with sane defaults and more parameters.

Parameters:

• logger_name (str | None) – ID of the logger to setup. If None, Python’s root logger will be used.

• format (str | None) – Use the specified format string for the handler. Defaults to levelname and message separated by a colon.

• datefmt (str | None) – Use the specified date/time format, as accepted by time.strftime().

• style (Literal['%', '{', '$']) – If format is specified, use this style for the format string. One of %, { or $ for printf-style, str.format() or string.Template respectively. Defaults to {.

• level (int | None) – Set the logger level to the specified level.

• handlers (Iterable[Handler] | None) – A list of logging.Handler instances to attach to the logger. If not provided, a new handler of the class set by the handler_class parameter will be created. Any handler in the list which does not have a formatter assigned will be assigned the formatter created in this function.

• force (bool) – Remove and close any existing handlers attached to the logger before carrying out the configuration as specified by the other arguments. Default to True so we always starts from a clean state each time we configure a logger. This is a life-saver in unittests in which loggers pollutes output.

• handler_class (type[TypeVar(THandler, bound= Handler)]) – Handler class to be used to create a new handler if none provided. Defaults to ExtraLogHandler.

• formatter_class (type[TypeVar(TFormatter, bound= Formatter)]) – Class of the formatter that will be setup on each handler if none found. Defaults to ExtraLogFormatter.

Return type:

Logger

Todo

Add more parameters for even greater configurability of the logger, by re-implementing those supported by logging.basicConfig.

class click_extra.logging.VerbosityOption(param_decls=None, default_logger=None, default='WARNING', metavar='LEVEL', type=Choice(['CRITICAL', 'ERROR', 'WARNING', 'INFO', 'DEBUG']), expose_value=False, help='Either CRITICAL, ERROR, WARNING, INFO, DEBUG.', is_eager=True, **kwargs)

Bases: ExtraOption

A pre-configured --verbosity/-v option.

Sets the level of the provided logger.

The selected verbosity level name is made available in the context in ctx.meta["click_extra.verbosity"].

Important

The internal click_extra logger level will be aligned to the value set via this option.

Set up the verbosity option.

Parameters:

default_logger (Logger | str | None) – If an instance of logging.Logger is provided, that’s the instance to which we will set the level set via the option. If the parameter is a string, we will fetch it with logging.getLogger. If not provided or None, the default Python root logger is used.

Todo

Write more documentation to detail in which case the user is responsible for setting up the logger, and when extra_basic_config is used.

property all_loggers: Generator[Logger, None, None]

Returns the list of logger IDs affected by the verbosity option.

Will returns Click Extra’s internal logger first, then the option’s custom logger.

default: t.Union[t.Any, t.Callable[[], t.Any]]

type: types.ParamType

is_flag: bool

is_bool_flag: bool

flag_value: t.Any

name: t.Optional[str]

opts: t.List[str]

secondary_opts: t.List[str]

reset_loggers()

Forces all loggers managed by the option to be reset to the default level.

Reset loggers in reverse order to ensure the internal logger is reset last. :rtype: None

Danger

Resseting loggers is extremely important for unittests. Because they’re global, loggers have tendency to leak and pollute their state between multiple test calls.

set_levels(ctx, param, value)

Set level of all loggers configured on the option.

Save the verbosity level name in the context.

Also prints the chosen value as a debug message via the internal click_extra logger.

Return type:

None

logger_name: str

The ID of the logger to set the level to.

This will be provided to logging.getLogger method to fetch the logger object, and as such, can be a dot-separated string to build hierarchical loggers.