Logging

The Python’s standard library logging module is a bit tricky to use. Click Extra provides pre-configured helpers with sane defaults to simplify the logging configuration.

Colored verbosity

--verbosity/-v is a pre-configured option which allow users of your CLI to set the log level of a logging.Logger instance.

Default behavior is to:

• print to <stderr>,

• send messages to the root logger,

• show WARNING-level messages and above,

• use {-style format strings,

• render logs with the {levelname}: {message} format,

• color the log’s {levelname} variable.

Integrated option

This option is part of @extra_command and @extra_group by default:

from click_extra import extra_command, echo

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

See that --verbosity/-v is featured 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.

This option 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.13.0
debug: {exec_name}      : click_extra.testing
debug: {version}        : 4.13.0
debug: {prog_name}      : my-cli
debug: {env_info}       : {'username': '-', 'guid': '41e3015f610950e8e8bd94e74d313ef', 'hostname': '-', 'hostfqdn': '-', 'uname': {'system': 'Linux', 'node': '-', 'release': '6.8.0-1020-azure', 'version': '#23-Ubuntu SMP Mon Dec  9 16:58:58 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.3 (main, Jan 17 2025, 18:03:48) [GCC 13.3.0]', 'compiler': 'GCC 13.3.0', 'build_date': 'Jan 17 2025 18:03:48', 'version_info': [3, 12, 3, 'final', 0], 'features': {'openssl': 'OpenSSL 3.0.13 30 Jan 2024', 'expat': 'expat_2.6.1', 'sqlite': '3.45.1', 'tkinter': '', 'zlib': '1.3', 'unicode_wide': True, 'readline': True, '64bit': True, 'ipv6': True, 'threading': True, 'urandom': True}}, 'time_utc': '2025-01-27 09:22:39.551986', '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.

Hint

Notice how, in the output above, each logger’s own level is printed as debug messages.

And how they’re all first set to DEBUG at the beginning of the command, then reset back to their default WARNING at the end.

Standalone option

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

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

@command
@verbosity_option
def vanilla_command():
    echo("It works!")
    logging.info("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 INFO
It works!
info: We're printing stuff.

Default logger

The --verbosity option is by default attached to the global root logger.

This allows you to use module-level helpers like logging.debug. That way you don’t have to worry about setting up your own logger. And logging messages can be easily produced with minimal code:

import logging
from click import command
from click_extra import verbosity_option

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

The --verbosity option print by default all messages at the WARNING level and above:

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

But each level can be selected with the option:

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

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

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

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

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

Caution

root is the default logger associated with --verbosity. Which means that, if not configured, all loggers will be printed at the verbosity level set by the option:

import logging
from click import command
from click_extra import verbosity_option

@command
@verbosity_option
def multiple_loggers_cli():
   # Use the default root logger.
   root_logger = logging.getLogger()
   root_logger.warning("Root warning message")
   root_logger.info("Root info message")

   # Create a custom logger and use it.
   my_logger = logging.getLogger("my_logger")
   my_logger.warning("My warning message")
   my_logger.info("My info message")

In that case, a normal invocation will only print the default WARNING messages:

$ multiple-loggers-cli
warning: Root warning message
warning: My warning message

And calling --verbosity INFO will print both root and my_logger messages of that level:

$ multiple-loggers-cli --verbosity INFO
warning: Root warning message
info: Root info message
warning: My warning message
info: My info message

To prevent this behavior, you can associate the --verbosity option with your own custom logger. This is explained in the next section.

Custom logger

The preferred way to customize log messages is to create your own logger and attach it to the --verbosity option.

This can be done with new_extra_logger. Here is how we can for example change the format of the log messages:

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

new_extra_logger(
  name="app_logger",
  format="{levelname} | {name} | {message}"
)

@command
@verbosity_option(default_logger="app_logger")
def custom_logger_cli():
     # Default root logger.
    logging.warning("Root logger warning")
    logging.info("Root logger info")

    # Use our custom logger.
    my_logger = logging.getLogger("app_logger")
    my_logger.warning("Custom warning")
    my_logger.info("Custom info")

That way the root logger keeps its default format, while the custom logger uses the new one:

$ custom-logger-cli
warning: Root logger warning
warning | app_logger | Custom warning

And changing the verbosity level will only affect the custom logger:

$ custom-logger-cli --verbosity INFO
warning: Root logger warning
warning | app_logger | Custom warning
info | app_logger | Custom info

Now if we don’t explicitly pass the custom logger to the --verbosity option, the default root logger will be tied to it instead:

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

new_extra_logger(
  name="app_logger",
  format="{levelname} | {name} | {message}"
)

@command
@verbosity_option
def root_verbosity_cli():
     # Default root logger.
    logging.warning("Root logger warning")
    logging.info("Root logger info")

    # Use our custom logger.
    my_logger = logging.getLogger("app_logger")
    my_logger.warning("Custom warning")
    my_logger.info("Custom info")

In that case the default behavior doesn’t change and messages are rendered in their own logger’s format, at the default WARNING level:

$ root-verbosity-cli
warning: Root logger warning
warning | app_logger | Custom warning

But changing the verbosity level only affects root, in the opposite of the previous example:

$ root-verbosity-cli --verbosity INFO
warning: Root logger warning
info: Root logger info
warning | app_logger | Custom warning

Important

By design, new loggers are always created as sub-loggers of root. And as such, their messages are propagated back to it.

But new_extra_logger always creates new loggers by setting their propagate attribute to False. This means that messages of new loggers won’t be propagated to their parents.

This is the reason why, in the example above, the root and app_logger loggers are independent.

Let’s experiment with that property and set the propagate attribute to True:

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

new_extra_logger(
   name="app_logger",
   propagate=True,
   format="{levelname} | {name} | {message}"
)

@command
@verbosity_option
def logger_propagation_cli():
   # Default root logger.
   logging.warning("Root logger warning")
   logging.info("Root logger info")

   # Use our custom logger.
   my_logger = logging.getLogger("app_logger")
   my_logger.warning("Custom warning")
   my_logger.info("Custom info")

$ logger-propagation-cli
warning: Root logger warning
warning | app_logger | Custom warning
warning: Custom warning

Here you can immediatly spot the issue with propagation: app_logger’s messages are displayed twice. Once in their custom format, and once in the format of the root logger.

See also

The reason for that hierarchycal design is to allow for dot-separated logger names, like foo.bar.baz. Which allows for even more granular control of loggers by filtering.

Tip

You can creatively configure loggers to produce any kind of messages, like this JSON-like format:

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

new_extra_logger(
   name="json_logger",
   format='{{"time": "{asctime}", "name": "{name}", "level": "{levelname}", "msg": "{message}"}}',
)

@command
@verbosity_option(default_logger="json_logger")
def json_logs_cli():
   my_logger = logging.getLogger("json_logger")
   my_logger.info("This is an info message.")

$ json-logs-cli --verbosity INFO
{"time": "2025-01-27 09:22:49,430", "name": "json_logger", "level": "info", "msg": "This is an info message."}

Hint

Becasue loggers are registered in a global registry, you can set them up in one place and use them in another. That is the idiomatic approach, which consist in always referring to them by name, as in all examples above.

But for convenience, you can pass the logger object directly to the option:

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

my_logger = new_extra_logger(name="app_logger")

@command
@verbosity_option(default_logger=my_logger)
def logger_object_cli():
   # Default root logger.
   logging.warning("Root warning message")
   logging.info("Root info message")

   # My custom logger.
   my_logger.warning("My warning message")
   my_logger.info("My info message")

$ logger-object-cli --verbosity INFO
warning: Root warning message
warning: My warning message
info: My info message

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"]

    level_from_logger = logging._levelToName[logging.getLogger().getEffectiveLevel()]

    echo(f"Level from context: {level_from_context}")
    echo(f"Level from logger: {level_from_logger}")

$ vanilla-command --verbosity INFO
Level from context: INFO
Level from logger: INFO

Internal click_extra logger

Click Extra has its own logger, named click_extra, which is used to print debug messages to inspect its own internal behavior.

click_extra.logging API

        classDiagram
  ExtraOption <|-- VerbosityOption
  Formatter <|-- ExtraFormatter
  Handler <|-- ExtraStreamHandler
    

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 integer level.

That’s our own version of logging._nameToLevel, with a twist:

• sorted from lowest to highest verbosity,

• excludes the following levels:

  • NOTSET, which is considered internal

  • WARN, which is obsolete

  • FATAL, which shouldn’t be used and has been 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 for 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.ExtraStreamHandler(stream=None)

Bases: Handler

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

Differs to the default logging.StreamHandler by using click.echo to support color printing to <stderr>.

Initialize the handler.

If stream is not specified, sys.stderr is used.

emit(record)

Use click.echo to print to <stderr>.

Return type:

None

class click_extra.logging.ExtraFormatter(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.extraBasicConfig(*, filename=None, filemode='a', format='{levelname}: {message}', datefmt=None, style='{', level=None, stream=None, handlers=None, force=False, encoding=None, errors='backslashreplace')

Configure the global root logger.

Same as Python standard library’s logging.basicConfig() but with better defaults:

Argument	extraBasicConfig() default	logging.basicConfig() default
handlers	A single instance of ExtraStreamHandler	False
style	{	%
format	{levelname}: {message}	%(levelname)s:%(name)s:%(message)s

Parameters:

• filename (str | None) – Specifies that a logging.FileHandler be created, using the specified filename, rather than a logging.StreamHandler.

• filemode (str) – If filename is specified, open the file in this mode. Defaults to a.

• format (str | None) – Use the specified format string for the handler. Defaults to {levelname}: {message}.

• 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 | str | None) – Set the root logger level to the specified level.

• stream (Optional[IO[Any]]) – Use the specified stream to initialize the logging.StreamHandler. Note that this argument is incompatible with filename - if both are present, a ValueError is raised.

• handlers (Iterable[Handler] | None) – If specified, this should be an iterable of already created handlers to add to the root logger. Any handlers which don’t already have a formatter set will be assigned the default formatter created in this function. Note that this argument is incompatible with filename or stream - if both are present, a ValueError is raised.

• force (bool) – If this keyword argument is specified as True, any existing handlers attached to the root logger are removed and closed, before carrying out the configuration as specified by the other arguments.

• encoding (str | None) – If this keyword argument is specified along with filename, its value is used when the logging.FileHandler is created, and thus used when opening the output file.

• errors (str | None) – If this keyword argument is specified along with filename, its value is used when the logging.FileHandler is created, and thus used when opening the output file. If not specified, the value backslashreplace is used. Note that if None is specified, it will be passed as such to open(), which means that it will be treated the same as passing errors.

Return type:

None

Important

Always keep the signature of this function, the default values of its parameters and its documentation in sync with the one from Python’s standard library.

Note

I don’t like the camel-cased name of this function and would have called it extra_basic_config(), but it’s kept this way for consistency with Python’s standard library.

click_extra.logging.new_extra_logger(name=None, *, handler_class=<class 'click_extra.logging.ExtraStreamHandler'>, formatter_class=<class 'click_extra.logging.ExtraFormatter'>, propagate=False, force=True, **kwargs)

Setup a logger in the style of Click Extra.

It is a wrapper around extraBasicConfig(), and takes the same keywords arguments.

But it also:

• Fetches the logger to configure or creates a new one if none is provided, by the

  name parameter.

• Sets the `logger’s propagate

  <https://docs.python.org/3/library/logging.html#logging.Logger.propagate>`_ attribute to False.

• Force removal of any existing handlers and formatters attached to the logger

  before adding the new default ones. I.e. same as setting basicConfig(force=True).

• Returns the logger object.

Parameters:

• name (str | None) – ID of the logger to setup. If None, Python’s root logger will be used. If a logger with the provided name is not found in the global registry, a new logger with that name will be created.

• handler_class (type[TypeVar(THandler, bound= Handler)]) – logging.Handler class that will be used by basicConfig() to create new handlers. Defaults to ExtraStreamHandler.

• formatter_class (type[TypeVar(TFormatter, bound= Formatter)]) – logging.Formatter class of the formatter that will be used by basicConfig() to setup handlers. Defaults to ExtraFormatter.

• propagate (bool) – same as :param:`basicConfig.propagate` and :param:`extraBasicConfig.propagate`. Defaults to False.

• force (bool) – same as :param:`basicConfig.force` and :param:`extraBasicConfig.force`. Defaults to True.

• kwargs – Any other keyword parameters supported by basicConfig() and extraBasicConfig().

Return type:

Logger

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. If no logger is provided, sets the level of the global root 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 use that to fetch it from the global registry with logging.getLogger. If no logger with that ID already exist or if the parameter is None, we will create a new logger with Click Extra’s default configuration.

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

Resetting 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.