cki_lib.logger

User-facing CLI text can go to stdout with print, but log records should go to stderr through Python’s logging module.

cki_lib.logger creates loggers in the cki hierarchy, and helps you configure logging for your application.

Get a logger

import logging
from cki_lib import logger

LOGGER: logging.Logger = logger.get_logger(__name__)
LOGGER.info("request accepted")

Pass cki, or a name with the cki. prefix, to keep that name. get_logger adds the cki. prefix to any other name. E.g. get_logger("mod_a") returns the logger cki.mod_a.

When a module is called directly as a script __name__ is "__main__", so use a fixed relevant string to avoid the logger name being cki.__main__.

The first call to get_logger can add one handler on the root logger. Later calls do not add a second handler.

Root handler

The root logger sits at the top of Python’s logging hierarchy, acting as the default parent for all custom loggers, bringing consistency through logging propagation.

logging.basicConfig() is the standard way to configure the root logger. It can set the level, the output stream, and the format.

To ensure consistent logging behavior across CKI services, CKI code relies on cki_lib.logger.get_logger for this instead.

cki-lib can configure the root logger, but it is optional! A root handler can conflict with log setup in the application or in another library.

⚠️ If you don’t want cki-lib to configure the root logger, leave CKI_LOGGING_FILE and CKI_LOGGING_FORMAT unset or empty.

Environment variables

All these variables are optional and not secrets.

• If CKI_LOGGING_FORMAT is unset or empty, the plain format is used.
• If CKI_LOGGING_FILE is unset or empty, the root logger writes to stderr.
• If both CKI_LOGGING_FILE and CKI_LOGGING_FORMAT are unset or empty, get_logger does not configure the root logger.
• If CKI_LOGGING_LEVEL is unset or empty, the cki logger inherits the root level, which Python sets to WARNING unless the application changes it.
• If URLLIB3_LOG_LEVEL is unset or empty, the urllib3 logger is left unchanged, which also means WARNING. If set to DEBUG, those logs include output from requests, which are exceptionally verbose.

Log levels

See the development guidelines for log levels.

• Use LOGGER.error() for an error that does not stop the application.
• Use LOGGER.exception() for an error inside an except block, to include the traceback in the log message.
• Use LOGGER.warning() for an exceptional event that does not require immediate attention, but could be useful when troubleshooting a problem.
• Use LOGGER.info() for relevant progress throughout the application. Avoid it in loops.
• Use LOGGER.debug() to trace detailed progress, verbose by design, but should never include sensitive data.

Sentry

cki_lib.logger does not send records to Sentry, but they can get there. If cki_lib.misc.sentry_init runs with SENTRY_DSN set, it calls sentry_sdk.init, which enables the SDK logging integration, which watches Python logging.

With the SDK defaults, a record at ERROR or above becomes a Sentry event. I.e.:

• LOGGER.error() sends the message as that event.
• LOGGER.exception(), inside an except block, sends the message and the traceback.
• LOGGER.warning() and LOGGER.info() do not become an event.

A warning and info records are kept as breadcrumbs and attached to the next Sentry event. If no later event is sent, the warning and info records are never uploaded. DEBUG is not sent.

Log formats

plain

Both plain and color use a simple pattern, with a UTC timestamp with six decimal digits.

%(asctime)s - [%(levelname)s] - %(name)s - %(message)s

E.g.: cki_lib.logger.get_logger("mod_a").warning("something happened") logs:

2010-01-02T00:00:00.000000 - [WARNING] - cki.mod_a - something happened

color

color uses the same pattern as plain, but adds ANSI colors to the whole line depending on the level:

• DEBUG: grey
• INFO: blue
• WARNING: yellow
• ERROR: red
• CRITICAL: bright magenta

json

The json format writes one JSON object per line.

{
  "timestamp": 1262390400.0,
  "logger": {"name": "cki", "level": "WARNING"},
  "message": "something happened",
  "extras": {}
}

The timestamp field holds seconds since the Unix epoch. The message field holds the log message after percent interpolation. The extras field holds logging_env keys from the current thread.

Values in extras follow these rules:

• A datetime value becomes ISO 8601 text.
• Any other object becomes its string form.
• When that conversion fails, the text is invalid: ClassName.

pack

The pack format also writes JSON, but using the schema for a Loki unpack query. Every value is a string. The formatter flattens nested logging_env data.

{
  "timestamp": "1262390400.0",
  "logger_name": "cki",
  "logger_level": "WARNING",
  "_entry": "something happened"
}

The timestamp field is a string copy of LogRecord.created. The _entry field holds the log message after percent interpolation.

The formatter stores logging_env keys under the extras prefix. A dict key foo becomes extras_foo. List index 0 becomes extras_0. Nested values add more segments, separated by an underscore. The formatter keeps letters, digits, and underscores in a key. The formatter replaces every other character with an underscore.

Datetime values follow the json rules. Failed string conversion uses invalid: ClassName, as in json.

Extra fields with logging_env

with logger.logging_env({"request_id": "abc"}):
    LOGGER.warning("rejected")

Inside the block, json and pack records on that thread include the keys. The context manager removes the keys when the block ends. It also removes them when the block raises an exception. Another thread does not see the keys. The plain and color formats ignore the keys.