fix(logging): redact production diagnostics and disable API access logs
This commit is contained in:
@@ -39,7 +39,7 @@ def create_app(settings: Settings | None = None) -> FastAPI:
|
||||
|
||||
@asynccontextmanager
|
||||
async def lifespan(_: FastAPI):
|
||||
configure_logging(settings.log_level)
|
||||
configure_logging(settings.log_level, production=settings.environment == "production")
|
||||
logger = logging.getLogger("kf_oj.api")
|
||||
logger.info("Platform API started")
|
||||
engine = None
|
||||
|
||||
@@ -16,7 +16,53 @@ class JsonFormatter(logging.Formatter):
|
||||
return json.dumps(payload, ensure_ascii=False)
|
||||
|
||||
|
||||
def configure_logging(level: str) -> None:
|
||||
class ProductionFormatter(logging.Formatter):
|
||||
"""Closed event vocabulary; arbitrary messages/arguments/tracebacks are private data."""
|
||||
|
||||
EVENTS = {
|
||||
("kf_oj.api", "Platform API started"): "api_started",
|
||||
("kf_oj.api", "Platform API stopped"): "api_stopped",
|
||||
("kf_oj.outbox", "outbox broker unavailable"): "outbox_broker_unavailable",
|
||||
("kf_oj.outbox", "outbox database unavailable"): "outbox_database_unavailable",
|
||||
}
|
||||
LOGGERS = {"kf_oj.api", "kf_oj.outbox", "uvicorn", "uvicorn.error", "uvicorn.access"}
|
||||
LEVELS = {
|
||||
logging.DEBUG: "DEBUG",
|
||||
logging.INFO: "INFO",
|
||||
logging.WARNING: "WARNING",
|
||||
logging.ERROR: "ERROR",
|
||||
logging.CRITICAL: "CRITICAL",
|
||||
}
|
||||
|
||||
def format(self, record: logging.LogRecord) -> str:
|
||||
# Do not call getMessage/formatException: library errors can contain
|
||||
# connection URIs, query parameters, source or diagnostic body bytes.
|
||||
event = "infrastructure_event"
|
||||
if isinstance(record.msg, str) and not record.args:
|
||||
event = self.EVENTS.get((record.name, record.msg), event)
|
||||
return json.dumps(
|
||||
{
|
||||
"timestamp": datetime.fromtimestamp(record.created, UTC).isoformat(),
|
||||
"level": self.LEVELS.get(record.levelno, "UNKNOWN"),
|
||||
"logger": record.name if record.name in self.LOGGERS else "infrastructure",
|
||||
"message": event,
|
||||
"exception_present": record.exc_info is not None,
|
||||
},
|
||||
ensure_ascii=False,
|
||||
)
|
||||
|
||||
|
||||
def configure_logging(level: str, *, production: bool = False) -> None:
|
||||
handler = logging.StreamHandler()
|
||||
handler.setFormatter(JsonFormatter())
|
||||
handler.setFormatter(ProductionFormatter() if production else JsonFormatter())
|
||||
logging.basicConfig(level=level, handlers=[handler], force=True)
|
||||
if production:
|
||||
# Uvicorn installs its own handlers before lifespan, which otherwise
|
||||
# bypass the root formatter when reporting an unhandled application error.
|
||||
for name in ("uvicorn", "uvicorn.error"):
|
||||
logger = logging.getLogger(name)
|
||||
logger.handlers.clear()
|
||||
logger.propagate = True
|
||||
access = logging.getLogger("uvicorn.access")
|
||||
access.handlers.clear()
|
||||
access.propagate = False
|
||||
|
||||
@@ -0,0 +1,60 @@
|
||||
"""Pure logging vocabulary checks, not evidence of real request/daemon log privacy."""
|
||||
|
||||
import json
|
||||
import logging
|
||||
|
||||
from kf_oj.core.logging import ProductionFormatter, configure_logging
|
||||
|
||||
|
||||
def test_production_does_not_serialize_unapproved_message_arguments_or_exception_data():
|
||||
record = logging.LogRecord(
|
||||
"external_library",
|
||||
logging.ERROR,
|
||||
"private/path",
|
||||
5,
|
||||
"temporary fixture token=%s",
|
||||
("fixture-only",),
|
||||
(ValueError, ValueError("fixture-only"), None),
|
||||
)
|
||||
value = json.loads(ProductionFormatter().format(record))
|
||||
assert value["message"] == "infrastructure_event"
|
||||
assert value["logger"] == "infrastructure"
|
||||
assert value["exception_present"] is True
|
||||
assert "fixture-only" not in json.dumps(value)
|
||||
assert "private/path" not in json.dumps(value)
|
||||
|
||||
|
||||
def test_only_exact_lifecycle_message_without_arguments_is_retained():
|
||||
record = logging.LogRecord(
|
||||
"kf_oj.api", logging.INFO, "unused", 1, "Platform API started", (), None
|
||||
)
|
||||
assert json.loads(ProductionFormatter().format(record))["message"] == "api_started"
|
||||
record.args = ("fixture-only",)
|
||||
assert json.loads(ProductionFormatter().format(record))["message"] == "infrastructure_event"
|
||||
|
||||
|
||||
def test_custom_logger_or_level_names_do_not_expand_the_output_vocabulary():
|
||||
record = logging.LogRecord("fixture-only", logging.ERROR, "unused", 1, {}, (), None)
|
||||
record.levelname = "fixture-only" * 1024
|
||||
value = ProductionFormatter().format(record)
|
||||
assert len(value) < 512
|
||||
assert "fixture-only" not in value
|
||||
|
||||
|
||||
def test_uvicorn_error_handlers_cannot_bypass_production_formatter(capsys):
|
||||
loggers = [
|
||||
logging.getLogger(name) for name in ("", "uvicorn", "uvicorn.error", "uvicorn.access")
|
||||
]
|
||||
original = [(logger, logger.handlers[:], logger.level, logger.propagate) for logger in loggers]
|
||||
try:
|
||||
configure_logging("INFO", production=True)
|
||||
assert not logging.getLogger("uvicorn.access").hasHandlers()
|
||||
logging.getLogger("uvicorn.error").error("fixture-only %s", "temporary value")
|
||||
value = json.loads(capsys.readouterr().err)
|
||||
assert value["message"] == "infrastructure_event"
|
||||
assert "fixture-only" not in json.dumps(value)
|
||||
finally:
|
||||
for logger, handlers, level, propagate in original:
|
||||
logger.handlers = handlers
|
||||
logger.setLevel(level)
|
||||
logger.propagate = propagate
|
||||
@@ -322,3 +322,10 @@ work; installing the profile alone does not route existing service logs or verif
|
||||
their privacy. The profile relies on the pinned systemd 262
|
||||
[namespace interface](https://github.com/systemd/systemd/blob/v262/man/systemd.exec.xml)
|
||||
and [journal configuration](https://github.com/systemd/systemd/blob/v262/man/journald.conf.xml).
|
||||
|
||||
Production API logging uses a closed event vocabulary and omits arbitrary library
|
||||
messages, arguments, paths and exception text. Uvicorn's separate error handlers
|
||||
are redirected through that formatter; installed API launchers disable access
|
||||
logging so request query strings are not copied into service logs. Development
|
||||
diagnostics remain separate. These ordinary formatting checks are not evidence
|
||||
of actual daemon, HTTP or upload log privacy; that is still a VM acceptance case.
|
||||
|
||||
@@ -16,7 +16,7 @@ ENTRYPOINTS = {
|
||||
"kf-delivery": "scripts.release",
|
||||
"kf-api": (
|
||||
"uvicorn kf_oj.api.app:create_app --factory --host 127.0.0.1 --port 8000 "
|
||||
"--no-proxy-headers --limit-concurrency 32 --backlog 64"
|
||||
"--no-proxy-headers --no-access-log --limit-concurrency 32 --backlog 64"
|
||||
),
|
||||
"kf-outbox-publisher": "kf_oj.workers.outbox",
|
||||
"kf-problem-import-worker": "kf_oj.workers.problem_import",
|
||||
|
||||
@@ -31,6 +31,7 @@ PYTHON_MODULES = {
|
||||
"--port",
|
||||
"8000",
|
||||
"--no-proxy-headers",
|
||||
"--no-access-log",
|
||||
"--limit-concurrency",
|
||||
"32",
|
||||
"--backlog",
|
||||
|
||||
Reference in New Issue
Block a user