Add JSON logging and Prometheus metrics from the service template - #110
Add JSON logging and Prometheus metrics from the service template#110lewisjared wants to merge 2 commits into
Conversation
Adopts the observability setup from copier-python-service, so this app lines up with the other Climate Resource services. - Every request emits one JSON wide event carrying the method, path, status, duration and a request_id, which is also stamped on the response as x-request-id. Set LOG_FORMAT=text for readable logs during local development. - Prometheus metrics are served from /metrics. - /livez and /readyz answer orchestrator probes. /readyz runs the checks on app.state.readiness_checks, and build_app registers one proving the REF database still answers a query. - /deploy/info reports the build stamps baked into the image. The template logs through the standard library, so the nine loguru call sites move across. loguru stays as a transitive dependency of climate-ref, and configure_logging re-points its sink at the standard library so those records land in the same stream rather than going out unstructured. Removes GET /api/v1/utils/health-check/, which nothing called.
✅ Deploy Preview for climate-ref canceled.
|
📝 WalkthroughWalkthroughThe backend adds structured logging, request correlation, health probes, deployment information, and Prometheus metrics. It removes the legacy health-check client API and updates OpenAPI generation, documentation, tests, and configuration. ChangesObservability and API operations
Sequence Diagram(s)sequenceDiagram
participant Client
participant WideEventMiddleware
participant HealthRouter
participant Database
participant Metrics
Client->>WideEventMiddleware: Send request
WideEventMiddleware->>HealthRouter: Route request
HealthRouter->>Database: Run readiness query
Database-->>HealthRouter: Return readiness result
HealthRouter-->>WideEventMiddleware: Return response
WideEventMiddleware->>Metrics: Record request and latency
WideEventMiddleware-->>Client: Return response with correlation headers
Merge Risk: 🟡 Moderate · up to Sensitive query values can enter access logs and readiness failures can expose internal details. These security issues should be fixed before merge; logging-context omissions also reduce correlation quality. 🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
Full details: Docstring CoverageExplanation Docstring coverage is 40.00% which is insufficient. The required threshold is 80.00%. Docstring coverage is scoped to functions touched by this diff. Analyzed 50 functions across 24 files. (5 skipped: 5 unsupported.)
✨ Finishing Touches 💡 1📝 Generate docstrings 💡
🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 4
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Team
Run ID: 9a1441bf-58f1-4abb-b1c5-327792cab2b6
⛔ Files ignored due to path filters (1)
backend/uv.lockis excluded by!**/*.lock
📒 Files selected for processing (33)
.env.samplebackend/pyproject.tomlbackend/src/ref_backend/analytics.pybackend/src/ref_backend/api/routes/aft.pybackend/src/ref_backend/api/routes/executions.pybackend/src/ref_backend/api/routes/utils.pybackend/src/ref_backend/builder.pybackend/src/ref_backend/core/config.pybackend/src/ref_backend/core/diagnostic_metadata.pybackend/src/ref_backend/core/ref.pybackend/src/ref_backend/deploy.pybackend/src/ref_backend/health.pybackend/src/ref_backend/log.pybackend/src/ref_backend/logging_config.pybackend/src/ref_backend/main.pybackend/src/ref_backend/metrics.pybackend/src/ref_backend/middleware.pybackend/src/ref_backend/models/diagnostics.pybackend/tests/test_api/test_routes/test_utils.pybackend/tests/test_deploy.pybackend/tests/test_health.pybackend/tests/test_logging_config.pybackend/tests/test_metrics.pybackend/tests/test_middleware.pybackend/tests/test_spa_fallback.pychangelog/110.breaking.mdchangelog/110.feature.mddocs/observability.mdfrontend/src/client/@tanstack/react-query.gen.tsfrontend/src/client/index.tsfrontend/src/client/sdk.gen.tsfrontend/src/client/types.gen.tsscripts/generate-client-sdk.sh
💤 Files with no reviewable changes (4)
- backend/tests/test_api/test_routes/test_utils.py
- frontend/src/client/types.gen.ts
- backend/src/ref_backend/api/routes/utils.py
- backend/src/ref_backend/log.py
Included review availability: Your plan provides up to 1 included review per hour; 0 remain after this review.
| ok = await ok | ||
| except Exception as exc: | ||
| logger.warning(f"Readiness check {name} failed", exc_info=True) | ||
| failures[name] = str(exc) |
There was a problem hiding this comment.
🔒 Security & Privacy | 🟡 Minor | ⚡ Quick win
🧩 Analysis chain
🏁 Script executed:
sed -n '1,140p' backend/src/ref_backend/health.py
printf '\n--- health references ---\n'
rg -n "health_router|readyz|readiness_checks|HTTPException|TrustedHost|AuthenticationMiddleware|middleware" backend/src/ref_backend -g '*.py'Repository: Climate-REF/ref-app
Length of output: 8383
🏁 Script executed:
sed -n '45,80p' backend/src/ref_backend/main.py
sed -n '1,120p' backend/src/ref_backend/middleware.pyRepository: Climate-REF/ref-app
Length of output: 5214
Information Disclosure (CWE-209): Generation of Error Message Containing Sensitive Information
Reachability: External · Exploitability: Moderate
Do not return readiness-check exception text.
When a check raises, str(exc) is included in the /readyz 503 response. Keep the detailed exception in logs and return a stable generic 503 response body.
| base = super().format(record) | ||
| extras = [] | ||
| for key, value in record.__dict__.items(): | ||
| if key in _RESERVED_LOG_RECORD_KEYS or key.startswith("_"): | ||
| continue | ||
| extras.append(f"{key}={value!r}") | ||
| if extras: | ||
| base = f"{base} | {' '.join(extras)}" |
There was a problem hiding this comment.
🎯 Functional Correctness | 🟡 Minor | ⚡ Quick win
Include environment context in text logs.
TextFormatter.format only appends fields from record.__dict__. With LOG_FORMAT=text, it omits _ENV_CONTEXT fields, which violates the documented logging contract. Merge _ENV_CONTEXT before adding record-specific extras.
Proposed fix
- extras = []
+ fields = dict(_ENV_CONTEXT)
for key, value in record.__dict__.items():
if key in _RESERVED_LOG_RECORD_KEYS or key.startswith("_"):
continue
- extras.append(f"{key}={value!r}")
+ fields[key] = value
+ extras = [f"{key}={value!r}" for key, value in fields.items()]📝 Committable suggestion
‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.
| base = super().format(record) | |
| extras = [] | |
| for key, value in record.__dict__.items(): | |
| if key in _RESERVED_LOG_RECORD_KEYS or key.startswith("_"): | |
| continue | |
| extras.append(f"{key}={value!r}") | |
| if extras: | |
| base = f"{base} | {' '.join(extras)}" | |
| base = super().format(record) | |
| fields = dict(_ENV_CONTEXT) | |
| for key, value in record.__dict__.items(): | |
| if key in _RESERVED_LOG_RECORD_KEYS or key.startswith("_"): | |
| continue | |
| fields[key] = value | |
| extras = [f"{key}={value!r}" for key, value in fields.items()] | |
| if extras: | |
| base = f"{base} | {' '.join(extras)}" |
| logging.getLogger(record["name"] or "loguru").log( | ||
| record["level"].no, | ||
| record["message"], | ||
| exc_info=record["exception"], | ||
| ) |
There was a problem hiding this comment.
🎯 Functional Correctness | 🟡 Minor | ⚡ Quick win
🔎 Supported by static analysis
🏁 Script executed:
#!/bin/sh
set -eu
# Inspect remaining bound Loguru calls that require context preservation.
rg -n -C 3 --type py 'from loguru import logger|\.bind\(' backend/src backend/testsRepository: Climate-REF/ref-app
Length of output: 636
🏁 Script executed:
#!/bin/sh
set -eu
sed -n '1,180p' backend/src/ref_backend/logging_config.py
printf '\n--- Loguru usage and formatter tests ---\n'
rg -n -C 3 --type py 'loguru_logger|logger\.bind|extra=|JsonFormatter|TextFormatter|_loguru_sink' backend/src backend/testsRepository: Climate-REF/ref-app
Length of output: 12373
🏁 Script executed:
#!/bin/sh
set -eu
python3 - <<'PY'
from pathlib import Path
path = Path("backend/src/ref_backend/logging_config.py")
lines = path.read_text().splitlines()
for start, end in ((70, 155),):
for number in range(start, min(end, len(lines)) + 1):
print(f"{number:4}: {lines[number - 1]}")
PYRepository: Climate-REF/ref-app
Length of output: 3475
🌐 Web query:
official Loguru documentation record extra logging.Logger.log extra Python documentation
💡 Result:
In Loguru, you can record extra information into the log record's extra dictionary using several methods, depending on whether the context is temporary, persistent, or per-log entry [1][2]. To record extra data in Loguru, you can use the following approaches: 1. Keyword arguments in logging calls: When you pass keyword arguments to any logging function (e.g., logger.info("Message", key="value")), Loguru automatically adds those keyword arguments to the extra dictionary of the log record [3][4][5]. These values are used for both message formatting and as part of the extra record attribute [3][5]. 2. The bind() method: Use logger.bind(kwargs) to create a new logger instance with persistent context [2]. Every message logged by this new instance will automatically include the bound keyword arguments in its extra dictionary [3][6]. This is ideal for adding consistent context like user IDs or server information across multiple log entries [2][7]. 3. The contextualize() method: Use logger.contextualize(kwargs) as a context manager (with the with statement) to temporarily add context to the extra dictionary for the duration of a specific block of code [8][2]. This is useful for request-specific data, such as a transaction ID, that should only appear in logs within a certain scope [2]. 4. The patch() method: Use logger.patch() to dynamically update the extra dictionary for every new message [1]. This is useful for adding values that need to be calculated at the time of logging, such as timestamps or other dynamic properties [1][6]. To display this information in your logs, you must ensure your format string includes the extra field (e.g., {extra[key]}) or simply {extra} to show the entire dictionary [1][2][7]. Example: from loguru import logger import sys # Configure a sink that displays extra data logger.remove logger.add(sys.stderr, format="{message} {extra}") # 1. Per-log entry via keyword arguments logger.info("Processing data", user_id=123) # 2. Persistent binding user_logger = logger.bind(session="abc") user_logger.info("User action") # 3. Temporary context with logger.contextualize(request_id="xyz"): logger.info("Inside request")
Citations:
- 1: https://loguru.readthedocs.io/en/latest/overview.html
- 2: https://realpython.com/python-loguru/
- 3: https://loguru.readthedocs.io/en/stable/api/logger.html
- 4: https://loguru.readthedocs.io/en/latest/api/logger.html
- 5: GitHub issue 1134 in Delgan/loguru (link omitted to avoid creating a cross-reference)
- 6: https://loguru.readthedocs.io/en/stable/_modules/loguru/_logger.html
- 7: https://loguru.readthedocs.io/en/stable/resources/migration.html
- 8: https://github.com/Delgan/loguru/blob/master/loguru/_logger.py
Forward bound Loguru context.
_loguru_sink drops record["extra"] before it calls logging.Logger.log. Bound fields such as request_id do not reach JsonFormatter or TextFormatter. Forward non-reserved fields through extra.
Proposed fix
record = message.record
+ extra = {
+ key: value
+ for key, value in record["extra"].items()
+ if key not in _RESERVED_LOG_RECORD_KEYS
+ }
logging.getLogger(record["name"] or "loguru").log(
record["level"].no,
record["message"],
exc_info=record["exception"],
+ extra=extra,
)| "request_id": request_id, | ||
| "method": request.method, | ||
| "path": request.url.path, | ||
| "query": dict(request.query_params), |
There was a problem hiding this comment.
🔒 Security & Privacy | 🟠 Major | ⚡ Quick win
Sensitive Data Exposure (CWE-532): Insertion of Sensitive Information into Log File
Reachability: External · Exploitability: Moderate
Do not log raw query parameters.
External callers can send sensitive values such as access_token. This middleware copies every query parameter into the access-log event without redaction. Remove query, or allowlist and redact values before logging.
1 participant
Add some additional observability tooling
request_id, which is also stamped on the response asx-request-id. SetLOG_FORMAT=textfor readable logs during local development./metrics./livezand/readyzanswer orchestrator probes./readyzruns the checks onapp.state.readiness_checks, andbuild_appregisters one proving the REF database still answers a query./deploy/inforeports the build stamps baked into the image, the same values the wide events carry.Removals
GET /api/v1/utils/health-check/is gone. Nothing called itscripts/generate-client-sdk.shused to pipe the app's stdout intoopenapi.json, which broke once the app started logging to stdout. It now writes the file from Python instead.Summary by CodeRabbit
New Features
/deploy/info./metrics.Breaking Changes
/api/v1/utils/health-check/endpoint. Use/livezand/readyzinstead.Documentation
Tests