diff --git a/litellm/_logging.py b/litellm/_logging.py index c73b5175a31..d2c1fe9039d 100644 --- a/litellm/_logging.py +++ b/litellm/_logging.py @@ -1,7 +1,10 @@ import ast import contextvars +import functools +import json import logging import os +import re import sys from datetime import datetime from logging import Formatter @@ -12,6 +15,7 @@ import litellm from litellm.constants import ( LITELLM_TRUNCATED_PAYLOAD_FIELD, LITELLM_TRUNCATION_STDOUT_SAFEGUARD_NOTE, + MAX_BASE64_LENGTH_STDOUT_LOG, MAX_STRING_LENGTH_STDOUT_LOG, ) from litellm.litellm_core_utils.env_utils import get_env_int @@ -76,6 +80,21 @@ def _redact_structured_value(key: str | None, value: str) -> str: return redact_structured_value(key, value) +_REDACTED_RECORD_ATTR: Final = "litellm_redacted" +_UNREDACTED_SCALAR_TYPES: Final = (bool, int, float, type(None)) + + +def _is_redacted(record: logging.LogRecord) -> bool: + return getattr(record, _REDACTED_RECORD_ATTR, False) is True + + +def _redact_extra_value(key: str, value: object) -> object: + try: + return json.loads(safe_dumps({key: value}, value_transform=_redact_structured_value))[key] + except (TypeError, ValueError, KeyError): + return _redact_string(str(value)) + + def redact_secrets(value: str) -> str: """Public API: redact known secret/credential patterns from an arbitrary string. @@ -148,11 +167,19 @@ class SecretRedactionFilter(logging.Filter): except Exception: pass + if isinstance(record.stack_info, str): + record.stack_info = _redact_string(record.stack_info) # rebind-ok: a Filter scrubs records in place + # Redact extra fields passed via logger.debug("msg", extra={...}) for key, value in list(record.__dict__.items()): - if key not in _STANDARD_RECORD_ATTRS and isinstance(value, str): - setattr(record, key, _redact_string(value)) + if key in _STANDARD_RECORD_ATTRS: + continue + if isinstance(value, str): + setattr(record, key, _redact_structured_value(key, value)) + elif not isinstance(value, _UNREDACTED_SCALAR_TYPES): + setattr(record, key, _redact_extra_value(key, value)) + setattr(record, _REDACTED_RECORD_ATTR, True) return True @@ -247,6 +274,37 @@ def _truncate_for_stdout_log(text: str, limit: int) -> str: return f"{text[:head_chars]}{_stdout_truncation_marker(len(text) - kept_chars)}{text[-tail_chars:]}" +_BYTES_PER_KIB: Final = 1024 +_BYTES_PER_MIB: Final = 1024 * 1024 + + +def format_base64_size(num_chars: int) -> str: + """Return a human-readable byte-size estimate from a base64 character count.""" + num_bytes: Final = num_chars * 3 / 4 + if num_bytes >= _BYTES_PER_MIB: + return f"{num_bytes / _BYTES_PER_MIB:.2f}MB" + if num_bytes >= _BYTES_PER_KIB: + return f"{num_bytes / _BYTES_PER_KIB:.1f}KB" + return f"{int(num_bytes)}B" + + +def _get_max_base64_length_stdout_log() -> int: + return get_env_int("MAX_BASE64_LENGTH_STDOUT_LOG", MAX_BASE64_LENGTH_STDOUT_LOG) + + +@functools.lru_cache(maxsize=8) +def _base64_run_pattern(min_chars: int) -> "re.Pattern[str]": + return re.compile(rf"(? str: + return f"[base64_data truncated: {format_base64_size(len(match.group(0)))}]" + + +def _collapse_base64_runs(text: str, limit: int) -> str: + return _base64_run_pattern(limit + 1).sub(_base64_run_placeholder, text) + + class StdoutLogTruncationFilter(logging.Filter): """Bounds how much of an oversized log line reaches stdout. @@ -254,31 +312,31 @@ class StdoutLogTruncationFilter(logging.Filter): request writes hundreds of KB to stdout, repeatedly as the exception propagates from the router to the proxy handler and into its traceback, all inline on the event loop. - DEBUG records pass through untouched, since dumping full payloads is the point of - `--detailed_debug`, and logging callbacks (OTEL, Datadog, etc.) don't run through - logging filters at all, so they still get the untruncated error. + At every level, a base64 run longer than MAX_BASE64_LENGTH_STDOUT_LOG collapses to a + size placeholder first: a multi-megabyte document upload otherwise costs seconds of + event-loop time per DEBUG line in the secret regex alone. The text around it stays, + since dumping payloads is the point of `--detailed_debug`, and logging callbacks + (OTEL, Datadog, etc.) don't run through logging filters at all, so they still get + the untouched record. """ _formatter = logging.Formatter() def filter(self, record: logging.LogRecord) -> bool: - if record.levelno < logging.INFO: - return True - - limit: Final = _get_max_string_length_stdout_log() - if limit <= 0: - return True - try: message: Final = record.getMessage() except (TypeError, ValueError): return True - if len(message) > limit: - record.msg = _truncate_for_stdout_log(message, limit) # rebind-ok: the Filter interface mutates the record - record.args = None # rebind-ok: args are consumed by the truncated message above + base64_limit: Final = _get_max_base64_length_stdout_log() + collapsed: Final = _collapse_base64_runs(message, base64_limit) if base64_limit > 0 else message + limit: Final = _get_max_string_length_stdout_log() if record.levelno >= logging.INFO else 0 + bounded: Final = _truncate_for_stdout_log(collapsed, limit) if 0 < limit < len(collapsed) else collapsed + if bounded != message: + record.msg = bounded # rebind-ok: the Filter interface mutates the record + record.args = None # rebind-ok: args are consumed by the rewritten message above - if isinstance(record.exc_info, tuple): + if limit > 0 and isinstance(record.exc_info, tuple): exc_text: Final = record.exc_text or self._formatter.formatException(record.exc_info) if len(exc_text) > limit: record.exc_text = _truncate_for_stdout_log( # rebind-ok: the Filter interface mutates the record @@ -440,6 +498,7 @@ def _get_standard_record_attrs() -> frozenset: _STANDARD_RECORD_ATTRS: Final = _get_standard_record_attrs() +_NON_EXTRA_RECORD_ATTRS: Final = _STANDARD_RECORD_ATTRS | {_REDACTED_RECORD_ATTR} # CorrelationContextFilter is the only legitimate source for these two JSON fields; # see JsonFormatter.format() for why they're excluded from the generic message-content @@ -480,7 +539,7 @@ class JsonFormatter(Formatter): # Include extra attributes passed via logger.debug("msg", extra={...}) for key, value in record.__dict__.items(): - if key not in _STANDARD_RECORD_ATTRS and key not in json_record: + if key not in _NON_EXTRA_RECORD_ATTRS and key not in json_record: json_record[key] = value # trace_id/session_id are reserved: CorrelationContextFilter is the only @@ -504,7 +563,7 @@ class JsonFormatter(Formatter): if record.exc_info: json_record["stacktrace"] = record.exc_text or self.formatException(record.exc_info) - return safe_dumps(json_record, value_transform=_redact_structured_value) + return safe_dumps(json_record, value_transform=None if _is_redacted(record) else _redact_structured_value) class CorrelationPlainFormatter(logging.Formatter): @@ -515,7 +574,8 @@ class CorrelationPlainFormatter(logging.Formatter): """ def format(self, record: logging.LogRecord) -> str: - formatted: Final = _redact_string(super().format(record)) + rendered: Final = super().format(record) + formatted: Final = rendered if _is_redacted(record) else _redact_string(rendered) trace_id: Final = getattr(record, "trace_id", None) session_id: Final = getattr(record, "session_id", None) if not trace_id and not session_id: @@ -533,8 +593,8 @@ def _setup_json_exception_handlers(formatter): # Create a handler with JSON formatting for exceptions error_handler: Final = logging.StreamHandler() error_handler.setFormatter(formatter) - error_handler.addFilter(_secret_filter) error_handler.addFilter(_stdout_truncation_filter) + error_handler.addFilter(_secret_filter) error_handler.addFilter(_correlation_filter) # Setup excepthook for uncaught exceptions diff --git a/litellm/constants.py b/litellm/constants.py index 6b984c2673c..e01f7d98f73 100644 --- a/litellm/constants.py +++ b/litellm/constants.py @@ -99,6 +99,7 @@ REDACTED_BY_LITELLM: Final = "redacted-by-litellm" REDACTED_TOOL_CALL_ARGUMENTS_PLACEHOLDER: Final = "{}" MAX_STRING_LENGTH_STDOUT_LOG: Final = get_env_int("MAX_STRING_LENGTH_STDOUT_LOG", 4096) +MAX_BASE64_LENGTH_STDOUT_LOG: Final = get_env_int("MAX_BASE64_LENGTH_STDOUT_LOG", 4096) # When true, adds detailed per-phase timing breakdown headers to responses. # Headers: x-litellm-timing-{pre-processing,llm-api,post-processing,message-copy}-ms diff --git a/litellm/litellm_core_utils/logging_utils.py b/litellm/litellm_core_utils/logging_utils.py index 44daef42e14..0f14b461d3d 100644 --- a/litellm/litellm_core_utils/logging_utils.py +++ b/litellm/litellm_core_utils/logging_utils.py @@ -7,7 +7,7 @@ from collections.abc import Iterator, Mapping, Sequence from datetime import datetime from typing import TYPE_CHECKING, Any, Final -from litellm._logging import verbose_logger +from litellm._logging import format_base64_size, verbose_logger from litellm.constants import ( BASE64_TRUNCATION_OFFLOAD_THRESHOLD_CHARS, MAX_BASE64_LENGTH_FOR_LOGGING, @@ -40,9 +40,6 @@ import litellm Helper utils used for logging callbacks """ -_BYTES_PER_KIB: Final = 1024 -_BYTES_PER_MIB: Final = 1024 * 1024 - # Regex matching data-URI base64 content: "data:;base64," # Captures: group(1)=mime_type, group(2)=base64_payload _DATA_URI_RE: Final = re.compile(r"data:([^;]+);base64,([A-Za-z0-9+/=]+)") @@ -52,23 +49,13 @@ _DATA_URI_RE: Final = re.compile(r"data:([^;]+);base64,([A-Za-z0-9+/=]+)") _MAX_TRUNCATION_DEPTH: Final = 20 -def _format_base64_size(num_chars: int) -> str: - """Return a human-readable byte-size estimate from a base64 character count.""" - num_bytes: Final = num_chars * 3 / 4 - if num_bytes >= _BYTES_PER_MIB: - return f"{num_bytes / _BYTES_PER_MIB:.2f}MB" - if num_bytes >= _BYTES_PER_KIB: - return f"{num_bytes / _BYTES_PER_KIB:.1f}KB" - return f"{int(num_bytes)}B" - - def _base64_data_uri_replacer(match: re.Match) -> str: """Replace a single base64 data-URI match with a size placeholder if too long.""" mime_type: Final = match.group(1) payload: Final = match.group(2) if len(payload) <= MAX_BASE64_LENGTH_FOR_LOGGING: return match.group(0) - size_str: Final = _format_base64_size(len(payload)) + size_str: Final = format_base64_size(len(payload)) return f"data:{mime_type};base64,[base64_data truncated: {size_str}]" diff --git a/tests/test_litellm/litellm_core_utils/test_logging_utils.py b/tests/test_litellm/litellm_core_utils/test_logging_utils.py index f9913f1935d..b446021a7dc 100644 --- a/tests/test_litellm/litellm_core_utils/test_logging_utils.py +++ b/tests/test_litellm/litellm_core_utils/test_logging_utils.py @@ -8,28 +8,28 @@ import pytest from litellm.litellm_core_utils import logging_utils from litellm.litellm_core_utils.logging_utils import ( - _format_base64_size, + format_base64_size, _truncate_base64_in_string, truncate_base64_in_messages, truncate_base64_in_messages_async, ) # --------------------------------------------------------------------------- -# _format_base64_size +# format_base64_size # --------------------------------------------------------------------------- class TestFormatBase64Size: def test_bytes_range(self): - assert _format_base64_size(4) == "3B" + assert format_base64_size(4) == "3B" def test_kb_range(self): # 2000 base64 chars ~ 1500 bytes ~ 1.5KB - assert "KB" in _format_base64_size(2000) + assert "KB" in format_base64_size(2000) def test_mb_range(self): # 2_000_000 base64 chars ~ 1.5MB - result = _format_base64_size(2_000_000) + result = format_base64_size(2_000_000) assert "MB" in result diff --git a/tests/test_litellm/test_logging.py b/tests/test_litellm/test_logging.py index bf3757e6886..81b0ecbcf5e 100644 --- a/tests/test_litellm/test_logging.py +++ b/tests/test_litellm/test_logging.py @@ -1,5 +1,6 @@ import ast import asyncio +import base64 import json import logging import re @@ -40,6 +41,7 @@ from litellm._logging import ( ) from litellm.constants import LITELLM_TRUNCATED_PAYLOAD_FIELD from litellm.integrations.custom_logger import CustomLogger +from litellm.litellm_core_utils import secret_redaction from litellm.types.utils import StandardLoggingPayload @@ -685,10 +687,17 @@ def _make_record(level: int, msg: str, args=(), exc_info=None) -> logging.LogRec ) +def _oversized_text(length: int) -> str: + return ("payload " * (length // 8 + 1))[:length] + + +_OVERSIZED_TEXT = _oversized_text(100_000) + + def test_oversized_info_record_is_truncated(monkeypatch): """An error string echoing a huge request payload must not reach stdout in full.""" monkeypatch.setenv("MAX_STRING_LENGTH_STDOUT_LOG", "500") - payload = "p" * 100_000 + payload = _OVERSIZED_TEXT record = _make_record(logging.INFO, "litellm.acompletion(model=%s) Exception %s", ("gpt-4", payload)) assert StdoutLogTruncationFilter().filter(record) is True @@ -696,8 +705,8 @@ def test_oversized_info_record_is_truncated(monkeypatch): message = record.getMessage() assert LITELLM_TRUNCATED_PAYLOAD_FIELD in message assert len(message) <= 500 - assert message.startswith("litellm.acompletion(model=gpt-4) Exception ppp") - assert message.endswith("ppp") + assert message.startswith("litellm.acompletion(model=gpt-4) Exception payload payload") + assert message.endswith("payload ") marker = _extract_marker(message) assert marker is not None @@ -721,7 +730,7 @@ def test_truncated_message_fits_the_configured_cap(monkeypatch): @pytest.mark.parametrize("payload_len", [501, 512, 1000, 9999, 100_000]) def test_truncated_message_never_exceeds_the_cap(monkeypatch, payload_len): monkeypatch.setenv("MAX_STRING_LENGTH_STDOUT_LOG", "500") - record = _make_record(logging.ERROR, "%s", ("p" * payload_len,)) + record = _make_record(logging.ERROR, "%s", (_oversized_text(payload_len),)) assert StdoutLogTruncationFilter().filter(record) is True @@ -747,7 +756,7 @@ def test_cap_leaving_no_room_for_the_marker_still_bounds_output(monkeypatch, cap def test_debug_record_is_not_truncated(monkeypatch): """--detailed_debug exists to dump full payloads, so DEBUG records pass through.""" monkeypatch.setenv("MAX_STRING_LENGTH_STDOUT_LOG", "500") - payload = "p" * 100_000 + payload = _OVERSIZED_TEXT record = _make_record(logging.DEBUG, "raw request %s", (payload,)) assert StdoutLogTruncationFilter().filter(record) is True @@ -757,7 +766,7 @@ def test_debug_record_is_not_truncated(monkeypatch): def test_truncation_disabled_by_zero_limit(monkeypatch): monkeypatch.setenv("MAX_STRING_LENGTH_STDOUT_LOG", "0") - payload = "p" * 100_000 + payload = _OVERSIZED_TEXT record = _make_record(logging.ERROR, "Exception %s", (payload,)) assert StdoutLogTruncationFilter().filter(record) is True @@ -785,7 +794,7 @@ def test_oversized_traceback_is_truncated(monkeypatch): def test_falsy_exc_info_is_not_formatted(monkeypatch): """Callers pass exc_info=False, which logging leaves on the record as a bool.""" monkeypatch.setenv("MAX_STRING_LENGTH_STDOUT_LOG", "500") - record = _make_record(logging.WARNING, "skipping malformed endpoint %s", ("p" * 100_000,), exc_info=False) + record = _make_record(logging.WARNING, "skipping malformed endpoint %s", (_OVERSIZED_TEXT,), exc_info=False) assert StdoutLogTruncationFilter().filter(record) is True @@ -824,13 +833,153 @@ def test_oversized_error_is_truncated_end_to_end(monkeypatch, caplog): monkeypatch.setenv("MAX_STRING_LENGTH_STDOUT_LOG", "500") with caplog.at_level(logging.INFO, logger="LiteLLM Router"): - verbose_router_logger.info("litellm.acompletion(model=%s) Exception %s", "gpt-4", "p" * 100_000) + verbose_router_logger.info("litellm.acompletion(model=%s) Exception %s", "gpt-4", _OVERSIZED_TEXT) emitted = "".join(record.getMessage() for record in caplog.records) assert LITELLM_TRUNCATED_PAYLOAD_FIELD in emitted assert len(emitted) <= 500 +_PDF_BASE64 = base64.b64encode(bytes(range(256)) * 18).decode() +_IMAGE_BASE64 = base64.b64encode(bytes(range(256)) * 24).decode() +_SHA256_HEX = "9f86d081884c7d659a2feaa0c55ad015a3bf4f1b2b0b822cd15d6c15b0f00a08" +_LIMIT_SIZED_TOKEN = "t" * 4096 + + +def test_debug_record_collapses_long_base64_runs(): + """A DEBUG line dumping a document upload keeps its text but not the megabytes of + base64, which cost seconds of event-loop time per line in the secret regex alone.""" + record = _make_record( + logging.DEBUG, + "receiving data: %s", + ( + f"{{'document': 'data:application/pdf;base64,{_PDF_BASE64}', " + f"'base64Source': '{_IMAGE_BASE64}', " + f"'sha256': '{_SHA256_HEX}', 'token': '{_LIMIT_SIZED_TOKEN}'}}", + ), + ) + + assert StdoutLogTruncationFilter().filter(record) is True + + assert record.getMessage() == ( + "receiving data: {'document': 'data:application/pdf;base64,[base64_data truncated: 4.5KB]', " + "'base64Source': '[base64_data truncated: 6.0KB]', " + f"'sha256': '{_SHA256_HEX}', 'token': '{_LIMIT_SIZED_TOKEN}'}}" + ) + + +@pytest.mark.parametrize("run_length,collapses", ((4096, False), (4097, True))) +def test_base64_run_collapses_only_past_the_limit(run_length, collapses): + record = _make_record(logging.DEBUG, "%s", ("A" * run_length,)) + + assert StdoutLogTruncationFilter().filter(record) is True + + assert ("[base64_data truncated: " in record.getMessage()) is collapses + + +@pytest.mark.parametrize("limit,collapses", (("0", False), ("100", True))) +def test_base64_collapse_limit_follows_the_env(monkeypatch, limit, collapses): + monkeypatch.setenv("MAX_BASE64_LENGTH_STDOUT_LOG", limit) + record = _make_record(logging.DEBUG, "%s", ("A" * 200,)) + + assert StdoutLogTruncationFilter().filter(record) is True + + assert ("[base64_data truncated: " in record.getMessage()) is collapses + + +def test_info_record_collapses_base64_before_truncating(monkeypatch): + """The collapse runs at every level ahead of the INFO+ cap, so an error echoing a + document upload comes out as its text around a size placeholder, not a head and tail.""" + monkeypatch.setenv("MAX_STRING_LENGTH_STDOUT_LOG", "500") + record = _make_record(logging.ERROR, "Exception: bad document %s (status 400)", ("A" * 100_000,)) + + assert StdoutLogTruncationFilter().filter(record) is True + + assert record.getMessage() == "Exception: bad document [base64_data truncated: 73.2KB] (status 400)" + + +def test_base64_collapse_applies_end_to_end(caplog): + """The proxy's own request dump must come out collapsed, not just the filter in isolation.""" + with caplog.at_level(logging.DEBUG, logger="LiteLLM Proxy"): + verbose_proxy_logger.debug("receiving data: %s", f"{{'document': 'data:application/pdf;base64,{_PDF_BASE64}'}}") + + emitted = "".join(record.getMessage() for record in caplog.records) + assert emitted == "receiving data: {'document': 'data:application/pdf;base64,[base64_data truncated: 4.5KB]'}" + + +class _CountingPattern: + def __init__(self, pattern: "re.Pattern[str]"): + self._pattern = pattern + self.calls = 0 + self.scanned_chars = 0 + + def sub(self, repl: str, string: str, count: int = 0) -> str: + self.calls += 1 + self.scanned_chars += len(string) + return self._pattern.sub(repl, string, count) + + +_REQUEST_DUMP = "{'model': 'gpt-4', 'messages': [{'role': 'user', 'content': 'hello world'}]}" + + +@pytest.mark.parametrize( + "formatter", + (CorrelationPlainFormatter(_PLAIN_LOG_FORMAT), JsonFormatter()), + ids=("plain", "json"), +) +def test_scrubbed_record_is_scanned_for_secrets_once(monkeypatch, formatter): + """Every pass of the secret regex over a multi-megabyte debug line costs seconds of + event-loop time, so a formatter must not rescan what SecretRedactionFilter scrubbed.""" + counting = _CountingPattern(secret_redaction._SECRET_RE) + monkeypatch.setattr(secret_redaction, "_SECRET_RE", counting) + monkeypatch.setattr("litellm._logging._ENABLE_SECRET_REDACTION", True) + record = _make_record(logging.DEBUG, "receiving data: %s", (_REQUEST_DUMP,)) + + assert StdoutLogTruncationFilter().filter(record) is True + assert SecretRedactionFilter().filter(record) is True + rendered = formatter.format(record) + + assert _REQUEST_DUMP in rendered + assert "litellm_redacted" not in rendered + assert counting.calls == 1 + assert counting.scanned_chars == len(f"receiving data: {_REQUEST_DUMP}") + + +def test_stack_info_is_scrubbed_before_the_plain_formatter(monkeypatch): + monkeypatch.setattr("litellm._logging._ENABLE_SECRET_REDACTION", True) + record = _make_record(logging.INFO, "call failed") + record.stack_info = "Stack (most recent call last):\n api_key=sk-1234567890abcdefghij" + + assert SecretRedactionFilter().filter(record) is True + rendered = CorrelationPlainFormatter(_PLAIN_LOG_FORMAT).format(record) + + assert "sk-1234567890abcdefghij" not in rendered + assert "Stack (most recent call last):" in rendered + + +@pytest.mark.parametrize("extra", ({1, "a"}, {"nested": {1, "a"}}), ids=("mixed_set", "nested_mixed_set")) +def test_unserializable_extra_never_breaks_the_filter(monkeypatch, extra): + monkeypatch.setattr("litellm._logging._ENABLE_SECRET_REDACTION", True) + record = _make_record(logging.WARNING, "request sent") + record.payload = extra + + assert SecretRedactionFilter().filter(record) is True + rendered = json.loads(JsonFormatter().format(record)) + + assert rendered["message"] == "request sent" + assert "payload" in rendered + + +def test_unscrubbed_record_is_still_redacted_by_the_formatter(monkeypatch): + """Records that never met SecretRedactionFilter (uvicorn's, in JSON mode) keep + their formatter-side redaction.""" + monkeypatch.setattr("litellm._logging._ENABLE_SECRET_REDACTION", True) + record = _make_record(logging.INFO, "key sk-1234567890abcdefghij") + + assert "sk-1234567890abcdefghij" not in JsonFormatter().format(record) + assert "sk-1234567890abcdefghij" not in CorrelationPlainFormatter(_PLAIN_LOG_FORMAT).format(record) + + def test_set_session_id_bounds_length(): """set_session_id() must bound length so an oversized caller-supplied value isn't repeated across every log line for the request.""" diff --git a/tests/test_litellm/test_secret_redaction.py b/tests/test_litellm/test_secret_redaction.py index 9fa748edec1..85933fbf9e8 100644 --- a/tests/test_litellm/test_secret_redaction.py +++ b/tests/test_litellm/test_secret_redaction.py @@ -636,11 +636,13 @@ def test_aws_credential_redaction_catches_quoted_values(): {"blob": {"authorization": f"Bearer {SECRET}"}}, {"blob": [f"Bearer {SECRET}"]}, {"blob": ({"nested": {"deep": SECRET}},)}, + {"master_key": "opaque-value-with-no-pattern"}, ), - ids=("set", "dict", "list", "nested"), + ids=("set", "dict", "list", "nested", "key_name"), ) def test_json_formatter_redacts_non_string_extra_values(extra): - """SecretRedactionFilter only scrubs str attrs, so containers must be caught on render.""" + """Container extras and key-named str extras must come out scrubbed, whichever of the + filter and the formatter does the work.""" buf = StringIO() handler = logging.StreamHandler(buf) handler.setFormatter(JsonFormatter())