From 84f1cca10225a8316567873fac2bb01eeddb1484 Mon Sep 17 00:00:00 2001 From: uditagrawal Date: Mon, 19 Oct 2026 20:39:20 -0700 Subject: [PATCH 1/4] feat: support configurable exclusion of JSON log fields Users wanting to drop a field such as written_ts had to subclass a formatter. json_logging.EXCLUDED_FIELDS now names fields to omit from every JSON record: standard, web and request log formatters, custom formatter subclasses, extra entries and props. The setting defaults to an empty tuple, so output is unchanged. It is read when a formatter is constructed, like the existing COMPONENT_* settings, and invalid values (a bare string, non-string entries) raise TypeError at that point rather than during a log call. Removal is one dict pop per excluded field after the record is built, so the default path adds only an empty loop. Adds tests for default output, single and multiple exclusions, empty lists, the standard, web and request formatters, extra/props, custom formatters, construction-time semantics and invalid configuration, and documents the option in README section 2.8. Fixes #98 --- CHANGELOG.md | 3 + README.md | 18 ++++ json_logging/__init__.py | 3 + json_logging/formatters.py | 19 ++++ tests/test_excluded_fields.py | 172 ++++++++++++++++++++++++++++++++++ 5 files changed, 215 insertions(+) create mode 100644 tests/test_excluded_fields.py diff --git a/CHANGELOG.md b/CHANGELOG.md index bd87d4d..63a6554 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -17,6 +17,9 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/). - fix: `init_sanic()` no longer raises `KeyError: 'format'` when Sanic 24.x and later omit formatter `format` keys; older Sanic logging configuration remains supported (PR #133). +- feat: `json_logging.EXCLUDED_FIELDS` omits the named fields from every JSON log record. Empty by default, so + output is unchanged. Fixes #98 + - fix: FastAPI application logs and `json_logging.get_correlation_id()` now use the request's correlation id instead of `-` in synchronous (`def`) endpoints (fixes #124, PR #123). When request instrumentation is enabled with `init_request_instrument(app)` (Python 3.9+): diff --git a/README.md b/README.md index 09cc7bc..b64f27d 100644 --- a/README.md +++ b/README.md @@ -34,6 +34,7 @@ author. 2.5 [Root logger](#25-root-logger) 2.6 [Custom log formatter](#26-custom-log-formatter) 2.7 [Exclude certain URL from request instrumentation](#27-exclude-certain-url-from-request-instrumentation) + 2.8 [Exclude fields from the JSON output](#28-exclude-fields-from-the-json-output) 3. [Configuration](#3-configuration) 4. [Python References](#4-python-references) 5. [Framework support plugin development](#5-framework-support-plugin-development) @@ -288,6 +289,23 @@ method like below: json_logging.init_request_instrument(app, exclude_url_patterns=[r'/exclude_from_request_instrumentation']) ``` +## 2.8 Exclude fields from the JSON output + +Set `json_logging.EXCLUDED_FIELDS` to omit fields from every JSON record, including request logs: + +```python +import json_logging + +json_logging.EXCLUDED_FIELDS = ["written_ts"] # or a tuple/set/frozenset of field names +json_logging.init_flask(enable_json=True) +``` + +- The default is `()`, so output is unchanged. +- Set it **before** calling `init_*()`: formatters read it when they are constructed, the same way as `COMPONENT_*`. +- A bare string, or a collection containing non-strings, raises `TypeError` when a formatter is built. +- Fields are removed after they are collected, so `extra` and `props` entries are removed too. +- Downstream log consumers may depend on fields such as `written_ts`, `correlation_id` or `level`. Exclude a field only when you know nothing downstream reads it. + # 3. Configuration logging library can be configured by setting the value in json_logging, all configuration must be placed before diff --git a/json_logging/__init__.py b/json_logging/__init__.py index 09b5b92..a2d6ac9 100644 --- a/json_logging/__init__.py +++ b/json_logging/__init__.py @@ -23,6 +23,9 @@ CREATE_CORRELATION_ID_IF_NOT_EXISTS = True JSON_SERIALIZER = lambda log: json.dumps(log, ensure_ascii=False, default=str) CORRELATION_ID_HEADERS = ['X-Correlation-ID', 'X-Request-ID'] +# Field names to omit from every JSON log record (e.g. 'written_ts'). Empty by default, so output is unchanged. +# Read when a formatter is constructed, so set it before calling init_*(). +EXCLUDED_FIELDS = () COMPONENT_ID = EMPTY_VALUE COMPONENT_NAME = EMPTY_VALUE COMPONENT_INSTANCE_INDEX = 0 diff --git a/json_logging/formatters.py b/json_logging/formatters.py index 9c3417d..8349dde 100644 --- a/json_logging/formatters.py +++ b/json_logging/formatters.py @@ -38,14 +38,31 @@ def _sanitize_log_msg(record): return record.getMessage().replace('\n', '_').replace('\r', '_').replace('\t', '_') +def _validated_excluded_fields(fields): + """ + Check json_logging.EXCLUDED_FIELDS and return it as a frozenset of field names. + :raises TypeError: if it is not a list/tuple/set/frozenset of strings (a bare string is rejected + because iterating it would exclude single characters) + """ + if isinstance(fields, (str, bytes)) or not isinstance(fields, (list, tuple, set, frozenset)): + raise TypeError("json_logging.EXCLUDED_FIELDS must be a list, tuple, set or frozenset of field names, " + "got %r" % (fields,)) + for field in fields: + if not isinstance(field, str): + raise TypeError("json_logging.EXCLUDED_FIELDS entries must be strings, got %r" % (field,)) + return frozenset(fields) + + class BaseJSONFormatter(logging.Formatter): """ Base class for JSON formatters """ base_object_common = {} + excluded_fields = frozenset() def __init__(self, *args, **kw): super(BaseJSONFormatter, self).__init__(*args, **kw) + self.excluded_fields = _validated_excluded_fields(json_logging.EXCLUDED_FIELDS) if json_logging.COMPONENT_ID and json_logging.COMPONENT_ID != json_logging.EMPTY_VALUE: self.base_object_common["component_id"] = json_logging.COMPONENT_ID if json_logging.COMPONENT_NAME and json_logging.COMPONENT_NAME != json_logging.EMPTY_VALUE: @@ -58,6 +75,8 @@ def format(self, record): Format the specified record as text. Overriding default python logging implementation """ log_object = self._format_log_object(record, request_util=json_logging._request_util) + for field in self.excluded_fields: + log_object.pop(field, None) return json_logging.JSON_SERIALIZER(log_object) def _format_log_object(self, record, request_util): diff --git a/tests/test_excluded_fields.py b/tests/test_excluded_fields.py new file mode 100644 index 0000000..09cee77 --- /dev/null +++ b/tests/test_excluded_fields.py @@ -0,0 +1,172 @@ +"""Configurable exclusion of JSON output fields (issue #98).""" +import io +import json +import logging + +import pytest +from helpers.handler import FormattedMessageCollectorHandler +from helpers.imports import undo_imports_from_package + + +@pytest.fixture +def fresh_json_logging(): + undo_imports_from_package("json_logging") + yield + undo_imports_from_package("json_logging") + + +def _capture(logger_name, formatter): + logger = logging.getLogger(logger_name) + logger.setLevel(logging.INFO) + logger.propagate = False + handler = FormattedMessageCollectorHandler() + handler.setFormatter(formatter) + logger.addHandler(handler) + return logger, handler + + +def _release(logger, handler): + logger.removeHandler(handler) + + +def test_default_output_keeps_every_standard_field(fresh_json_logging): + import json_logging + assert json_logging.EXCLUDED_FIELDS == () + json_logging.init_non_web(enable_json=True) + logger, handler = _capture("excl-default", json_logging.JSONLogFormatter()) + try: + logger.info("hello") + finally: + _release(logger, handler) + record = json.loads(handler.messages[0]) + for field in ("written_at", "written_ts", "msg", "type", "logger", "thread", "level", "module", "line_no"): + assert field in record, field + + +def test_excluding_written_ts_removes_only_that_field(fresh_json_logging): + import json_logging + json_logging.EXCLUDED_FIELDS = ["written_ts"] + json_logging.init_non_web(enable_json=True) + logger, handler = _capture("excl-one", json_logging.JSONLogFormatter()) + try: + logger.info("hello") + finally: + _release(logger, handler) + record = json.loads(handler.messages[0]) + assert "written_ts" not in record + assert record["written_at"] and record["msg"] == "hello" and record["type"] == "log" + + +def test_excluding_several_fields_keeps_the_rest(fresh_json_logging): + import json_logging + json_logging.EXCLUDED_FIELDS = ("written_ts", "thread", "module") + json_logging.init_non_web(enable_json=True) + logger, handler = _capture("excl-many", json_logging.JSONLogFormatter()) + try: + logger.info("hello") + finally: + _release(logger, handler) + record = json.loads(handler.messages[0]) + assert not {"written_ts", "thread", "module"} & set(record) + assert {"written_at", "msg", "type", "logger", "level", "line_no"} <= set(record) + + +def test_empty_exclusion_list_is_the_same_as_the_default(fresh_json_logging): + import json_logging + json_logging.EXCLUDED_FIELDS = [] + json_logging.init_non_web(enable_json=True) + logger, handler = _capture("excl-empty", json_logging.JSONLogFormatter()) + try: + logger.info("hello") + finally: + _release(logger, handler) + assert "written_ts" in json.loads(handler.messages[0]) + + +def test_web_formatter_honours_exclusion_and_keeps_correlation_id(fresh_json_logging): + import flask + import json_logging + json_logging.EXCLUDED_FIELDS = ["written_ts"] + app = flask.Flask(__name__) + json_logging.init_flask(enable_json=True) + json_logging.init_request_instrument(app) + logger, handler = _capture("excl-web", json_logging.JSONLogWebFormatter()) + try: + with app.test_request_context("/", headers={"X-Correlation-ID": "kept-1"}): + logger.info("in request") + finally: + _release(logger, handler) + record = json.loads(handler.messages[0]) + assert "written_ts" not in record + assert record["correlation_id"] == "kept-1" + + +def test_request_log_formatter_honours_exclusion(fresh_json_logging): + import flask + import json_logging + json_logging.EXCLUDED_FIELDS = ("written_ts", "response_time_ms") + app = flask.Flask(__name__) + json_logging.init_flask(enable_json=True) + json_logging.init_request_instrument(app) + buf = io.StringIO() + request_logger = json_logging.get_request_logger() + handler = logging.StreamHandler(buf) + handler.setFormatter(json_logging.JSONRequestLogFormatter()) + request_logger.handlers = [handler] + app.test_client().get("/nothing-here") + record = json.loads(buf.getvalue().splitlines()[0]) + assert "written_ts" not in record and "response_time_ms" not in record + assert record["type"] == "request" and "response_status" in record + + +def test_extra_and_props_fields_are_excluded_too(fresh_json_logging): + import json_logging + json_logging.EXCLUDED_FIELDS = ["secret_token", "tenant"] + json_logging.init_non_web(enable_json=True) + logger, handler = _capture("excl-extra", json_logging.JSONLogFormatter()) + try: + logger.info("hello", extra={"secret_token": "abc", "props": {"tenant": "acme", "job": "j1"}}) + finally: + _release(logger, handler) + record = json.loads(handler.messages[0]) + assert "secret_token" not in record and "tenant" not in record + assert record["job"] == "j1" + + +def test_custom_formatter_subclass_inherits_exclusion(fresh_json_logging): + import json_logging + + class Custom(json_logging.JSONLogFormatter): + def _format_log_object(self, record, request_util): + obj = super()._format_log_object(record, request_util) + obj["custom"] = "yes" + return obj + + json_logging.EXCLUDED_FIELDS = ["written_ts"] + json_logging.init_non_web(enable_json=True, custom_formatter=Custom) + logger, handler = _capture("excl-custom", Custom()) + try: + logger.info("hello") + finally: + _release(logger, handler) + record = json.loads(handler.messages[0]) + assert "written_ts" not in record and record["custom"] == "yes" + + +def test_formatter_created_before_the_setting_keeps_its_original_configuration(fresh_json_logging): + """Settings are read when a formatter is constructed, like the existing COMPONENT_* settings.""" + import json_logging + early = json_logging.JSONLogFormatter() + json_logging.EXCLUDED_FIELDS = ["written_ts"] + late = json_logging.JSONLogFormatter() + record = logging.LogRecord("x", logging.INFO, __file__, 1, "m", None, None) + assert "written_ts" in json.loads(early.format(record)) + assert "written_ts" not in json.loads(late.format(record)) + + +@pytest.mark.parametrize("bad", ["written_ts", None, 42, ["written_ts", 7], [b"written_ts"]]) +def test_invalid_configuration_is_rejected_when_a_formatter_is_built(fresh_json_logging, bad): + import json_logging + json_logging.EXCLUDED_FIELDS = bad + with pytest.raises(TypeError): + json_logging.JSONLogFormatter() From 8a576b85b37e3747efe4c304206527d3b650c3b9 Mon Sep 17 00:00:00 2001 From: uditagrawal Date: Mon, 19 Oct 2026 21:54:43 -0700 Subject: [PATCH 2/4] test: isolate request-logger state in the field-exclusion tests test_request_log_formatter_honours_exclusion replaced the whole handler list of the process-wide 'flask-request-logger' and never restored it. Running the two request-logger tests left the logger with only the test's buffer handler and parent=None, so the stdout handler that init_request_instrument() installs was gone. Restore the logger's handlers in a finally block, and snapshot and restore the logger's full state (handlers, level, parent, propagate, disabled) in a fixture used by the tests that call init_request_instrument(). Also add tests that exclusion does not mutate the LogRecord, that exception text is removed only when exc_info is excluded, and that formatters built at different times keep their own snapshots. The file passes in forward and reversed order and when each test runs alone. --- tests/test_excluded_fields.py | 67 ++++++++++++++++++++++++++++++++--- 1 file changed, 63 insertions(+), 4 deletions(-) diff --git a/tests/test_excluded_fields.py b/tests/test_excluded_fields.py index 09cee77..a6a0d55 100644 --- a/tests/test_excluded_fields.py +++ b/tests/test_excluded_fields.py @@ -15,6 +15,17 @@ def fresh_json_logging(): undo_imports_from_package("json_logging") +@pytest.fixture +def restored_request_logger(): + """init_request_instrument() adds a handler to a process-wide logger and detaches it from its parent. + Restore the logger's full state afterwards, so tests cannot depend on each other.""" + logger = logging.getLogger("flask-request-logger") + saved = (list(logger.handlers), logger.level, logger.parent, logger.propagate, logger.disabled) + yield logger + logger.handlers, level, logger.parent, logger.propagate, logger.disabled = saved + logger.setLevel(level) + + def _capture(logger_name, formatter): logger = logging.getLogger(logger_name) logger.setLevel(logging.INFO) @@ -83,7 +94,7 @@ def test_empty_exclusion_list_is_the_same_as_the_default(fresh_json_logging): assert "written_ts" in json.loads(handler.messages[0]) -def test_web_formatter_honours_exclusion_and_keeps_correlation_id(fresh_json_logging): +def test_web_formatter_honours_exclusion_and_keeps_correlation_id(fresh_json_logging, restored_request_logger): import flask import json_logging json_logging.EXCLUDED_FIELDS = ["written_ts"] @@ -101,7 +112,7 @@ def test_web_formatter_honours_exclusion_and_keeps_correlation_id(fresh_json_log assert record["correlation_id"] == "kept-1" -def test_request_log_formatter_honours_exclusion(fresh_json_logging): +def test_request_log_formatter_honours_exclusion(fresh_json_logging, restored_request_logger): import flask import json_logging json_logging.EXCLUDED_FIELDS = ("written_ts", "response_time_ms") @@ -110,10 +121,14 @@ def test_request_log_formatter_honours_exclusion(fresh_json_logging): json_logging.init_request_instrument(app) buf = io.StringIO() request_logger = json_logging.get_request_logger() + original_handlers = request_logger.handlers[:] handler = logging.StreamHandler(buf) handler.setFormatter(json_logging.JSONRequestLogFormatter()) - request_logger.handlers = [handler] - app.test_client().get("/nothing-here") + try: + request_logger.handlers = [handler] + app.test_client().get("/nothing-here") + finally: + request_logger.handlers = original_handlers record = json.loads(buf.getvalue().splitlines()[0]) assert "written_ts" not in record and "response_time_ms" not in record assert record["type"] == "request" and "response_status" in record @@ -170,3 +185,47 @@ def test_invalid_configuration_is_rejected_when_a_formatter_is_built(fresh_json_ json_logging.EXCLUDED_FIELDS = bad with pytest.raises(TypeError): json_logging.JSONLogFormatter() + + +def test_exclusion_does_not_mutate_the_log_record(fresh_json_logging): + import json_logging + json_logging.EXCLUDED_FIELDS = ["written_ts", "msg"] + formatter = json_logging.JSONLogFormatter() + record = logging.LogRecord("n", logging.INFO, __file__, 3, "hello %s", ("x",), None) + record.props = {"tenant": "acme"} + before = dict(record.__dict__) + output = json.loads(formatter.format(record)) + assert "msg" not in output and "written_ts" not in output + assert record.__dict__ == before + assert record.getMessage() == "hello x" + + +def test_exception_formatting_is_removed_only_when_excluded(fresh_json_logging): + import json_logging + try: + raise ValueError("boom") + except ValueError: + import sys + exc_info = sys.exc_info() + record = logging.LogRecord("n", logging.ERROR, __file__, 3, "failed", None, exc_info) + + default = json.loads(json_logging.JSONLogFormatter().format(record)) + assert "ValueError: boom" in default["exc_info"] + + json_logging.EXCLUDED_FIELDS = ["exc_info"] + excluded = json.loads(json_logging.JSONLogFormatter().format(record)) + assert "exc_info" not in excluded and excluded["msg"] == "failed" + + +def test_formatters_built_at_different_times_keep_their_own_snapshots(fresh_json_logging): + import json_logging + record = logging.LogRecord("n", logging.INFO, __file__, 3, "m", None, None) + first = json_logging.JSONLogFormatter() + json_logging.EXCLUDED_FIELDS = ["written_ts"] + second = json_logging.JSONLogFormatter() + json_logging.EXCLUDED_FIELDS = ["written_ts", "thread"] + third = json_logging.JSONLogFormatter() + + assert "written_ts" in json.loads(first.format(record)) and "thread" in json.loads(first.format(record)) + assert "written_ts" not in json.loads(second.format(record)) and "thread" in json.loads(second.format(record)) + assert "written_ts" not in json.loads(third.format(record)) and "thread" not in json.loads(third.format(record)) From 236317bcd5eb6be25c97c4b51466bafa89bf54a9 Mon Sep 17 00:00:00 2001 From: uditagrawal Date: Mon, 19 Oct 2026 22:39:20 -0700 Subject: [PATCH 3/4] fix: validate EXCLUDED_FIELDS before init changes any state An invalid json_logging.EXCLUDED_FIELDS was only detected when a formatter was constructed. By then init_flask() and the other web init functions had already set _current_framework and _request_util, so correcting the setting and calling init again failed with 'Can not call init more than once'. In init_request_instrument() the stdout handler was attached before the error, so a retry left two handlers. - Validate the setting at the start of __init() and init_request_instrument(). - Accept unicode field names on Python 2 by using the module's basestring shim. - Restore the werkzeug logger as well as the request logger in the tests. - Add subprocess regression tests for recovery after invalid configuration. --- README.md | 4 +- json_logging/__init__.py | 11 +++- json_logging/formatters.py | 5 +- tests/test_excluded_fields.py | 113 +++++++++++++++++++++++++++++++--- 4 files changed, 120 insertions(+), 13 deletions(-) diff --git a/README.md b/README.md index b64f27d..16bb810 100644 --- a/README.md +++ b/README.md @@ -302,7 +302,9 @@ json_logging.init_flask(enable_json=True) - The default is `()`, so output is unchanged. - Set it **before** calling `init_*()`: formatters read it when they are constructed, the same way as `COMPONENT_*`. -- A bare string, or a collection containing non-strings, raises `TypeError` when a formatter is built. +- A bare string, or a collection containing non-strings, raises `TypeError` from `init_*()`, + `init_request_instrument()` or a formatter constructor. The `init_*()` and `init_request_instrument()` calls + validate the setting before changing any state, so you can correct it and call them again. - Fields are removed after they are collected, so `extra` and `props` entries are removed too. - Downstream log consumers may depend on fields such as `written_ts`, `correlation_id` or `level`. Exclude a field only when you know nothing downstream reads it. diff --git a/json_logging/__init__.py b/json_logging/__init__.py index a2d6ac9..86289bb 100644 --- a/json_logging/__init__.py +++ b/json_logging/__init__.py @@ -6,7 +6,8 @@ from json_logging import util from json_logging.dto import RequestResponseDTOBase, DefaultRequestResponseDTO -from json_logging.formatters import JSONRequestLogFormatter, JSONLogFormatter, JSONLogWebFormatter +from json_logging.formatters import JSONRequestLogFormatter, JSONLogFormatter, JSONLogWebFormatter, \ + _validated_excluded_fields from json_logging.framework_base import BaseRequestInfoExtractor, BaseResponseInfoExtractor, \ BaseAppRequestInstrumentationConfigurator, \ BaseFrameworkConfigurator @@ -103,6 +104,9 @@ def __init(framework_name=None, custom_formatter=None, enable_json=False): if not issubclass(custom_formatter, logging.Formatter): raise ValueError('custom_formatter is not subclass of logging.Formatter', custom_formatter) + # Validate before any global state changes, so a corrected setting can be retried in the same process + _validated_excluded_fields(EXCLUDED_FIELDS) + if not enable_json and not ENABLE_JSON_LOGGING: _logger.warning( "JSON format is not enabled, normal log will be in plain text but request logging still in JSON format! " @@ -163,7 +167,10 @@ def init_request_instrument(app=None, custom_formatter=None, exclude_url_pattern raise ValueError('request_response_dto_class is not subclass of json_logging.RequestInfoBase', custom_formatter) - configurator = _current_framework['app_request_instrumentation_configurator']() + # Validate before hooks and handlers are installed, so a failed call leaves nothing behind + _validated_excluded_fields(EXCLUDED_FIELDS) + + configurator =_current_framework['app_request_instrumentation_configurator']() configurator.config(app, request_response_dto_class, exclude_url_patterns=exclude_url_patterns) formatter = custom_formatter if custom_formatter else JSONRequestLogFormatter diff --git a/json_logging/formatters.py b/json_logging/formatters.py index 8349dde..fae91b5 100644 --- a/json_logging/formatters.py +++ b/json_logging/formatters.py @@ -44,11 +44,12 @@ def _validated_excluded_fields(fields): :raises TypeError: if it is not a list/tuple/set/frozenset of strings (a bare string is rejected because iterating it would exclude single characters) """ - if isinstance(fields, (str, bytes)) or not isinstance(fields, (list, tuple, set, frozenset)): + if isinstance(fields, (basestring, bytes)) or not isinstance(fields, (list, tuple, set, frozenset)): raise TypeError("json_logging.EXCLUDED_FIELDS must be a list, tuple, set or frozenset of field names, " "got %r" % (fields,)) for field in fields: - if not isinstance(field, str): + # basestring also accepts unicode names on Python 2; on Python 3 it is str, so bytes are rejected + if not isinstance(field, basestring): raise TypeError("json_logging.EXCLUDED_FIELDS entries must be strings, got %r" % (field,)) return frozenset(fields) diff --git a/tests/test_excluded_fields.py b/tests/test_excluded_fields.py index a6a0d55..644e00d 100644 --- a/tests/test_excluded_fields.py +++ b/tests/test_excluded_fields.py @@ -2,11 +2,18 @@ import io import json import logging +import os +import subprocess +import sys +import textwrap +from pathlib import Path import pytest from helpers.handler import FormattedMessageCollectorHandler from helpers.imports import undo_imports_from_package +ROOT = Path(__file__).resolve().parents[1] + @pytest.fixture def fresh_json_logging(): @@ -17,13 +24,21 @@ def fresh_json_logging(): @pytest.fixture def restored_request_logger(): - """init_request_instrument() adds a handler to a process-wide logger and detaches it from its parent. - Restore the logger's full state afterwards, so tests cannot depend on each other.""" - logger = logging.getLogger("flask-request-logger") - saved = (list(logger.handlers), logger.level, logger.parent, logger.propagate, logger.disabled) - yield logger - logger.handlers, level, logger.parent, logger.propagate, logger.disabled = saved - logger.setLevel(level) + """init_flask()/init_request_instrument() change process-wide loggers: the request logger gets a handler and is + detached from its parent, and the werkzeug logger is disabled and given a JSON formatter. Restore the full state + of both afterwards, so tests cannot depend on each other.""" + loggers = [logging.getLogger(name) for name in ("flask-request-logger", "werkzeug")] + saved = [(logger, list(logger.handlers), [h.formatter for h in logger.handlers], logger.level, logger.parent, + logger.propagate, logger.disabled) for logger in loggers] + yield loggers[0] + for logger, handlers, formatters, level, parent, propagate, disabled in saved: + logger.handlers = handlers + for handler, formatter in zip(handlers, formatters): + handler.setFormatter(formatter) + logger.setLevel(level) + logger.parent = parent + logger.propagate = propagate + logger.disabled = disabled def _capture(logger_name, formatter): @@ -179,7 +194,8 @@ def test_formatter_created_before_the_setting_keeps_its_original_configuration(f assert "written_ts" not in json.loads(late.format(record)) -@pytest.mark.parametrize("bad", ["written_ts", None, 42, ["written_ts", 7], [b"written_ts"]]) +@pytest.mark.parametrize("bad", ["written_ts", u"written_ts", b"written_ts", None, 42, {"written_ts": 1}, + ["written_ts", 7], [b"written_ts"], [None]]) def test_invalid_configuration_is_rejected_when_a_formatter_is_built(fresh_json_logging, bad): import json_logging json_logging.EXCLUDED_FIELDS = bad @@ -187,6 +203,87 @@ def test_invalid_configuration_is_rejected_when_a_formatter_is_built(fresh_json_ json_logging.JSONLogFormatter() +@pytest.mark.parametrize("good", [["written_ts"], [u"written_ts"], ("written_ts",), {"written_ts"}, + frozenset([u"written_ts"])]) +def test_valid_configuration_types_are_accepted(fresh_json_logging, good): + """u"" literals are native str on Python 3; on Python 2 the validator uses basestring so unicode names pass.""" + import json_logging + json_logging.EXCLUDED_FIELDS = good + record = logging.LogRecord("n", logging.INFO, __file__, 3, "m", None, None) + assert "written_ts" not in json.loads(json_logging.JSONLogFormatter().format(record)) + + +def _run_isolated(code): + """Run code in a fresh interpreter: init_*() changes process-wide state that cannot be fully undone in-process.""" + env = dict(os.environ, PYTHONWARNINGS="ignore") + env.pop("ENABLE_JSON_LOGGING", None) + env["PYTHONPATH"] = os.pathsep.join([str(ROOT), env.get("PYTHONPATH", "")]) + return subprocess.run([sys.executable, "-c", textwrap.dedent(code)], cwd=str(ROOT), env=env, + capture_output=True, text=True, timeout=60) + + +@pytest.mark.parametrize("init_call", ["init_flask(enable_json=True)", "init_flask(enable_json=False)", + "init_non_web(enable_json=True)"]) +def test_invalid_configuration_does_not_poison_a_later_init(init_call): + result = _run_isolated(""" + import json_logging + json_logging.EXCLUDED_FIELDS = "written_ts" # invalid: a bare string + try: + json_logging.%(call)s + except TypeError: + pass + else: + raise AssertionError("invalid EXCLUDED_FIELDS was accepted") + assert json_logging._current_framework is None and json_logging._request_util is None + + json_logging.EXCLUDED_FIELDS = ["written_ts"] + json_logging.%(call)s # must not raise "Can not call init more than once" + if json_logging._current_framework is not None: + try: + json_logging.%(call)s + except RuntimeError as exc: + assert "Can not call init more than once" in str(exc) + else: + raise AssertionError("duplicate initialisation was not rejected") + print("OK") + """ % {"call": init_call}) + assert result.returncode == 0, result.stdout + result.stderr + assert "OK" in result.stdout + + +def test_invalid_configuration_does_not_leave_request_instrumentation_half_installed(): + result = _run_isolated(""" + import io, json, logging, sys + import flask + import json_logging + json_logging.init_flask(enable_json=True) + app = flask.Flask("isolated") + request_logger = logging.getLogger("flask-request-logger") + + json_logging.EXCLUDED_FIELDS = "written_ts" # invalid, set after a valid init_flask() + try: + json_logging.init_request_instrument(app) + except TypeError: + pass + else: + raise AssertionError("invalid EXCLUDED_FIELDS was accepted") + assert request_logger.handlers == [] and not app.before_request_funcs and not app.after_request_funcs + assert logging.getLogger("werkzeug").disabled is False + + json_logging.EXCLUDED_FIELDS = ["written_ts"] + sys.stdout = buf = io.StringIO() # the request logger writes to sys.stdout + json_logging.init_request_instrument(app) + app.test_client().get("/missing", headers={"X-Correlation-ID": "retry-1"}) + sys.stdout = sys.__stdout__ + assert len(request_logger.handlers) == 1 + records = [json.loads(line) for line in buf.getvalue().splitlines()] + assert len(records) == 1 and records[0]["correlation_id"] == "retry-1" and "written_ts" not in records[0] + print("OK") + """) + assert result.returncode == 0, result.stdout + result.stderr + assert "OK" in result.stdout + + def test_exclusion_does_not_mutate_the_log_record(fresh_json_logging): import json_logging json_logging.EXCLUDED_FIELDS = ["written_ts", "msg"] From 08350d7e3c46c2bc6d5732500b3660071b75f46b Mon Sep 17 00:00:00 2001 From: uditagrawal Date: Tue, 20 Oct 2026 16:37:54 -0700 Subject: [PATCH 4/4] test: cover the issue #98 setup and restore all logging state - Add an end-to-end test of the setup from issue #98: an application logger has a StreamHandler before init_flask(). The test checks that the library installs JSONLogWebFormatter on that handler with the configured exclusions, adds no handler, and keeps the X-Correlation-ID. Cases: written_ts excluded, the default, and correlation_id plus an unknown field name. - Replace the request-logger fixture with an autouse fixture that restores logging._defaultFormatter and, for every existing logger, its handlers, handler formatters, level, parent, propagation and disabled state; loggers created by a test are reset. Before this, init_*() left _defaultFormatter and the formatters of unrelated library loggers (urllib3, requests) changed. - Remove a snapshot test fully covered by test_formatters_built_at_different_times_keep_their_own_snapshots. - README 2.8: exclusions apply only to formatters that use BaseJSONFormatter.format(); the option changes the JSON schema and is not a security redaction control. - Restore a space lost in init_request_instrument() during the earlier edit. --- README.md | 7 +- json_logging/__init__.py | 2 +- tests/test_excluded_fields.py | 121 +++++++++++++++++++++++++--------- 3 files changed, 98 insertions(+), 32 deletions(-) diff --git a/README.md b/README.md index 16bb810..f9f3ee2 100644 --- a/README.md +++ b/README.md @@ -306,7 +306,12 @@ json_logging.init_flask(enable_json=True) `init_request_instrument()` or a formatter constructor. The `init_*()` and `init_request_instrument()` calls validate the setting before changing any state, so you can correct it and call them again. - Fields are removed after they are collected, so `extra` and `props` entries are removed too. -- Downstream log consumers may depend on fields such as `written_ts`, `correlation_id` or `level`. Exclude a field only when you know nothing downstream reads it. +- Exclusions apply to formatters that use `BaseJSONFormatter.format()`: the built-in JSON formatters and subclasses + that inherit or call it. A custom `logging.Formatter` that does not use it must filter fields itself. +- Excluding a field changes the JSON schema. Downstream log consumers may depend on fields such as `written_ts`, + `correlation_id` or `level`; exclude a field only when you know nothing downstream reads it. +- This is an output-formatting option, **not** a security redaction or data-loss-prevention control. A sensitive + value can still appear in the message, in another field, or through another handler or formatter. # 3. Configuration diff --git a/json_logging/__init__.py b/json_logging/__init__.py index 86289bb..3c30552 100644 --- a/json_logging/__init__.py +++ b/json_logging/__init__.py @@ -170,7 +170,7 @@ def init_request_instrument(app=None, custom_formatter=None, exclude_url_pattern # Validate before hooks and handlers are installed, so a failed call leaves nothing behind _validated_excluded_fields(EXCLUDED_FIELDS) - configurator =_current_framework['app_request_instrumentation_configurator']() + configurator = _current_framework['app_request_instrumentation_configurator']() configurator.config(app, request_response_dto_class, exclude_url_patterns=exclude_url_patterns) formatter = custom_formatter if custom_formatter else JSONRequestLogFormatter diff --git a/tests/test_excluded_fields.py b/tests/test_excluded_fields.py index 644e00d..2be0c9c 100644 --- a/tests/test_excluded_fields.py +++ b/tests/test_excluded_fields.py @@ -22,23 +22,51 @@ def fresh_json_logging(): undo_imports_from_package("json_logging") -@pytest.fixture -def restored_request_logger(): - """init_flask()/init_request_instrument() change process-wide loggers: the request logger gets a handler and is - detached from its parent, and the werkzeug logger is disabled and given a JSON formatter. Restore the full state - of both afterwards, so tests cannot depend on each other.""" - loggers = [logging.getLogger(name) for name in ("flask-request-logger", "werkzeug")] - saved = [(logger, list(logger.handlers), [h.formatter for h in logger.handlers], logger.level, logger.parent, - logger.propagate, logger.disabled) for logger in loggers] - yield loggers[0] - for logger, handlers, formatters, level, parent, propagate, disabled in saved: - logger.handlers = handlers - for handler, formatter in zip(handlers, formatters): - handler.setFormatter(formatter) - logger.setLevel(level) - logger.parent = parent - logger.propagate = propagate - logger.disabled = disabled +def _logger_state(logger): + return (list(logger.handlers), [h.formatter for h in logger.handlers], logger.level, logger.parent, + logger.propagate, logger.disabled) + + +@pytest.fixture(autouse=True) +def restore_logging_state(): + """init_*() change process-wide logging state: logging._defaultFormatter, the formatter of every handler on + every existing logger, and the framework loggers (handlers, parent, disabled). _capture() changes logger levels + and propagation. Restore all of it after each test, also when the test fails, so tests cannot affect each + other or other test modules. The root logger is left alone: init_*() do not change it, and pytest replaces + its own capture handlers on it between test phases.""" + manager = logging.Logger.manager + default_formatter = logging._defaultFormatter + saved = {name: _logger_state(logger) for name, logger in manager.loggerDict.items() + if isinstance(logger, logging.Logger)} + yield + logging._defaultFormatter = default_formatter + for name, logger in list(manager.loggerDict.items()): + if not isinstance(logger, logging.Logger): + continue + if name not in saved: # created by the test: return it to a new logger's state + for handler in list(logger.handlers): + logger.removeHandler(handler) + handler.close() + logger.setLevel(logging.NOTSET) + logger.propagate, logger.disabled = True, False + if logger.parent is None: # init_request_instrument() detaches the request logger + logger.parent = logging.root + continue + _restore_logger(logger, saved[name]) + + +def _restore_logger(logger, state): + handlers, formatters, level, parent, propagate, disabled = state + for handler in logger.handlers: + if handler not in handlers: + handler.close() + logger.handlers = handlers + for handler, formatter in zip(handlers, formatters): + handler.setFormatter(formatter) + logger.setLevel(level) + logger.parent = parent + logger.propagate = propagate + logger.disabled = disabled def _capture(logger_name, formatter): @@ -109,7 +137,7 @@ def test_empty_exclusion_list_is_the_same_as_the_default(fresh_json_logging): assert "written_ts" in json.loads(handler.messages[0]) -def test_web_formatter_honours_exclusion_and_keeps_correlation_id(fresh_json_logging, restored_request_logger): +def test_web_formatter_honours_exclusion_and_keeps_correlation_id(fresh_json_logging): import flask import json_logging json_logging.EXCLUDED_FIELDS = ["written_ts"] @@ -127,7 +155,7 @@ def test_web_formatter_honours_exclusion_and_keeps_correlation_id(fresh_json_log assert record["correlation_id"] == "kept-1" -def test_request_log_formatter_honours_exclusion(fresh_json_logging, restored_request_logger): +def test_request_log_formatter_honours_exclusion(fresh_json_logging): import flask import json_logging json_logging.EXCLUDED_FIELDS = ("written_ts", "response_time_ms") @@ -183,17 +211,6 @@ def _format_log_object(self, record, request_util): assert "written_ts" not in record and record["custom"] == "yes" -def test_formatter_created_before_the_setting_keeps_its_original_configuration(fresh_json_logging): - """Settings are read when a formatter is constructed, like the existing COMPONENT_* settings.""" - import json_logging - early = json_logging.JSONLogFormatter() - json_logging.EXCLUDED_FIELDS = ["written_ts"] - late = json_logging.JSONLogFormatter() - record = logging.LogRecord("x", logging.INFO, __file__, 1, "m", None, None) - assert "written_ts" in json.loads(early.format(record)) - assert "written_ts" not in json.loads(late.format(record)) - - @pytest.mark.parametrize("bad", ["written_ts", u"written_ts", b"written_ts", None, 42, {"written_ts": 1}, ["written_ts", 7], [b"written_ts"], [None]]) def test_invalid_configuration_is_rejected_when_a_formatter_is_built(fresh_json_logging, bad): @@ -326,3 +343,47 @@ def test_formatters_built_at_different_times_keep_their_own_snapshots(fresh_json assert "written_ts" in json.loads(first.format(record)) and "thread" in json.loads(first.format(record)) assert "written_ts" not in json.loads(second.format(record)) and "thread" in json.loads(second.format(record)) assert "written_ts" not in json.loads(third.format(record)) and "thread" not in json.loads(third.format(record)) + + +@pytest.mark.parametrize("excluded, absent", [ + (["written_ts"], {"written_ts"}), # the request in issue #98 + ((), set()), # default: nothing removed + (["correlation_id", "no_such_field"], {"correlation_id"}), # unknown names are ignored +]) +def test_issue_98_handler_added_before_init_flask_gets_the_configured_json_output(fresh_json_logging, excluded, + absent): + """The setup from issue #98: an application logger already has a StreamHandler when init_flask() runs. The + library must install its JSON formatter on that handler, with the configured exclusions, without adding one.""" + import flask + import json_logging + stream = io.StringIO() + logger = logging.getLogger("issue-98-app") + logger.setLevel(logging.DEBUG) + handler = logging.StreamHandler(stream) + logger.addHandler(handler) + assert handler.formatter is None + + json_logging.EXCLUDED_FIELDS = excluded + app = flask.Flask(__name__) + json_logging.init_flask(enable_json=True) + json_logging.init_request_instrument(app, exclude_url_patterns=[r'/health', r'/metrics']) + + @app.route("/work") + def work(): + logger.info("handled request") + return json_logging.get_correlation_id() + + response = app.test_client().get("/work", headers={"X-Correlation-ID": "issue-98"}) + + assert response.get_data(as_text=True) == "issue-98" # exclusion changes output only, not the ID lookup + assert logger.handlers == [handler] + assert type(handler.formatter) is json_logging.JSONLogWebFormatter + records = [json.loads(line) for line in stream.getvalue().splitlines()] + assert len(records) == 1 + record = records[0] + assert not absent & set(record), record + expected = {"written_at", "written_ts", "msg", "type", "level", "logger", "correlation_id"} - absent + assert expected <= set(record), record + assert record["msg"] == "handled request" and record["level"] == "INFO" and record["type"] == "log" + if "correlation_id" not in absent: + assert record["correlation_id"] == "issue-98"