Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Remove structlog #957

Merged
merged 8 commits into from
Aug 7, 2024
Merged
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Prev Previous commit
Next Next commit
Replace structlog with logging
  • Loading branch information
leplatrem committed Aug 6, 2024
commit 0b894935011b15865f23f09ea5d13a9b4ef1b4b5
4 changes: 2 additions & 2 deletions ctms/app.py
Original file line number Diff line number Diff line change
@@ -81,9 +81,9 @@ async def log_request_middleware(request: Request, call_next):

context.update({"status_code": status_code, "duration_s": duration_s})
if response is None:
web_logger.error(log_line, **context)
web_logger.error(log_line, extra=context)
else:
web_logger.info(log_line, **context)
web_logger.info(log_line, extra=context)
return response


61 changes: 9 additions & 52 deletions ctms/log.py
Original file line number Diff line number Diff line change
@@ -5,11 +5,9 @@
import sys
from typing import Any, Dict, List, Optional

import structlog
from dockerflow.logging import request_id_context
from fastapi import Request
from starlette.routing import Match
from structlog.types import Processor


def configure_logging(
@@ -22,17 +20,6 @@ def configure_logging(
:param logging_level: The logging level, such as DEBUG or INFO.
:param log_sqlalchemy: Include SQLAlchemy engine logs, such as SQL statements
"""

if use_mozlog:
structlog_fmt_prep: Processor = structlog.stdlib.render_to_log_kwargs
structlog_dev_processors: List[Processor] = []
else:
structlog_fmt_prep = structlog.stdlib.ProcessorFormatter.wrap_for_formatter
structlog_dev_processors = [
structlog.stdlib.add_logger_name,
structlog.stdlib.add_log_level,
structlog.processors.TimeStamper(fmt="iso"),
]
logging_config = {
"version": 1,
"disable_existing_loggers": False,
@@ -42,71 +29,41 @@ def configure_logging(
},
},
"formatters": {
"dev_console": {
"()": structlog.stdlib.ProcessorFormatter,
"processor": structlog.dev.ConsoleRenderer(colors=True),
"foreign_pre_chain": structlog_dev_processors,
},
"mozlog_json": {
"()": "dockerflow.logging.JsonLogFormatter",
"logger_name": "ctms",
},
"text": {
"format": "%(asctime)s %(levelname)-8s [%(rid)s] %(name)-15s %(message)s",
"datefmt": "%Y-%m-%d %H:%M:%S",
},
},
"handlers": {
"humans": {
"console": {
"level": logging_level,
"class": "logging.StreamHandler",
"stream": sys.stdout,
"formatter": "dev_console",
"level": logging.DEBUG,
"filters": ["request_id"],
"formatter": "mozlog_json" if use_mozlog else "text",
"stream": sys.stdout,
},
"null": {
"class": "logging.NullHandler",
},
"mozlog": {
"class": "logging.StreamHandler",
"stream": sys.stdout,
"formatter": "mozlog_json",
"level": logging.DEBUG,
"filters": ["request_id"],
},
},
"root": {
"handlers": ["mozlog" if use_mozlog else "humans"],
"level": logging_level,
},
"loggers": {
"": {"handlers": ["console"], "level": logging_level},
"alembic": {"level": logging_level},
"ctms": {"level": logging_level},
"uvicorn": {"level": logging_level},
"uvicorn.access": {"handlers": ["null"], "propagate": False},
"sqlalchemy.engine": {
"handlers": ["mozlog" if use_mozlog else "humans"],
"level": logging_level if log_sqlalchemy else logging.WARNING,
"propagate": False,
},
},
}
logging.config.dictConfig(logging_config)

structlog_processors: List[Processor] = [structlog.stdlib.filter_by_level]
structlog_processors.extend(structlog_dev_processors)
structlog_processors.extend(
[
structlog.stdlib.PositionalArgumentsFormatter(),
structlog.processors.StackInfoRenderer(),
structlog.processors.format_exc_info,
structlog.processors.UnicodeDecoder(),
structlog_fmt_prep,
]
)
structlog.configure(
processors=structlog_processors,
context_class=dict,
logger_factory=structlog.stdlib.LoggerFactory(),
wrapper_class=structlog.stdlib.BoundLogger,
cache_logger_on_first_use=True,
)
return logging_config


21 changes: 2 additions & 19 deletions poetry.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

1 change: 0 additions & 1 deletion pyproject.toml
Original file line number Diff line number Diff line change
@@ -27,7 +27,6 @@ dockerflow = {extras = ["fastapi"], version = "^2024.4.2"}
sentry-sdk = "^2.11.0"
lxml = "^5.2.2"
prometheus-client = "0.20.0"
structlog = "^24.4.0"
colorama = "^0.4.6"
psycopg2 = "^2.9.9"
google-auth = "^2.32.0"
11 changes: 6 additions & 5 deletions tests/unit/routers/contacts/test_api_post.py
Original file line number Diff line number Diff line change
@@ -1,9 +1,9 @@
"""Unit tests for POST /ctms (create record)"""

import logging
from uuid import UUID

import pytest
from structlog.testing import capture_logs

from tests.unit.conftest import SAMPLE_CONTACT_PARAMS

@@ -120,12 +120,13 @@ def _change_primary_email(contact):
_compare_written_contacts(saved_contacts[0], orig_sample, email_id)


def test_create_with_non_json_is_error(client):
def test_create_with_non_json_is_error(client, caplog):
"""When non-JSON is posted /ctms, a 422 is returned"""
data = b"this is not JSON"
with capture_logs() as cap_logs:
with caplog.at_level(logging.INFO, logger="ctms.web"):
resp = client.post("/ctms", content=data)

assert resp.status_code == 422
assert resp.json()["detail"][0]["msg"] == "JSON decode error"
assert len(cap_logs) == 1
assert "trace" not in cap_logs[0]
assert len(caplog.records) == 1
assert not hasattr(caplog.records[0], "trace")
leplatrem marked this conversation as resolved.
Show resolved Hide resolved
10 changes: 5 additions & 5 deletions tests/unit/routers/contacts/test_api_put.py
Original file line number Diff line number Diff line change
@@ -1,9 +1,9 @@
"""Unit tests for PUT /ctms/{email_id} (Create or update)"""

import logging
from uuid import UUID, uuid4

import pytest
from structlog.testing import capture_logs

from ctms.schemas import ContactPutSchema
from tests.unit.conftest import SAMPLE_CONTACT_PARAMS
@@ -128,13 +128,13 @@ def _change_primary_email(contact):
_compare_written_contacts(saved_contacts[0], orig_sample, email_id)


def test_put_with_not_json_is_error(client, dbsession):
def test_put_with_not_json_is_error(client, dbsession, caplog):
"""Calling PUT with a text body is a 422 validation error."""
email_id = str(uuid4())
data = b"make a contact please"
with capture_logs() as caplogs:
with caplog.at_level(logging.INFO, logger="ctms.web"):
resp = client.put(f"/ctms/{email_id}", content=data)
assert resp.status_code == 422
assert resp.json()["detail"][0]["msg"] == "JSON decode error"
assert len(caplogs) == 1
assert "trace" not in caplogs[0]
assert len(caplog.records) == 1
assert not hasattr(caplog.records[0], "trace")
leplatrem marked this conversation as resolved.
Show resolved Hide resolved
20 changes: 10 additions & 10 deletions tests/unit/routers/test_platform.py
Original file line number Diff line number Diff line change
@@ -1,24 +1,24 @@
import json
import logging
from pathlib import Path
from unittest import mock

import pytest
from sqlalchemy.exc import TimeoutError as SQATimeoutError
from structlog.testing import capture_logs

from ctms.app import app


def test_read_root(anon_client):
def test_read_root(anon_client, caplog):
"""The site root redirects to the Swagger docs"""
with capture_logs() as caplogs:
with caplog.at_level(level=logging.INFO, logger="ctms.web"):
resp = anon_client.get("/")
assert resp.status_code == 200
assert len(resp.history) == 1
prev_resp = resp.history[0]
assert prev_resp.status_code == 307 # Temporary Redirect
assert prev_resp.headers["location"] == "./docs"
assert len(caplogs) == 2
assert len(caplog.records) == 2


def test_read_version(anon_client):
@@ -53,9 +53,9 @@ def test_crash_unauthorized(anon_client):
assert resp.json() == {"detail": "Not authenticated"}


def test_read_heartbeat(anon_client):
def test_read_heartbeat(anon_client, caplog):
"""The platform calls /__heartbeat__ to check backing services."""
with capture_logs() as cap_logs:
with caplog.at_level(logging.INFO, logger="ctms.web"):
resp = anon_client.get("/__heartbeat__")
assert resp.status_code == 200
data = resp.json()
@@ -64,7 +64,7 @@ def test_read_heartbeat(anon_client):
"details": {},
"status": "ok",
}
assert len(cap_logs) == 1
assert len(caplog.messages) == 1


@mock.patch("ctms.routers.platform.SessionLocal")
@@ -99,9 +99,9 @@ def test_read_health(anon_client):
assert resp.status_code == 200


def test_get_metrics(anon_client, setup_metrics):
def test_get_metrics(anon_client, setup_metrics, caplog):
"""An anonoymous user can request metrics."""
with capture_logs() as cap_logs:
with caplog.at_level(logging.INFO, logger="ctms.web"):
resp = anon_client.get("/metrics")
assert resp.status_code == 200
assert len(cap_logs) == 1
assert len(caplog.messages) == 1
leplatrem marked this conversation as resolved.
Show resolved Hide resolved
Loading