-
Notifications
You must be signed in to change notification settings - Fork 1
fix: activate structured logging pipeline -- wire 8-sink system, integrate Uvicorn, suppress spam #572
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
fix: activate structured logging pipeline -- wire 8-sink system, integrate Uvicorn, suppress spam #572
Changes from 5 commits
71bb26c
4fe7c78
f8ab851
37b6d97
449df2a
3749bc1
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change | ||||||||||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
|
@@ -1133,3 +1133,114 @@ Backup settings live in the `backup` namespace with runtime editability via `Bac | |||||||||||||||||||||||||
| | `GET` | `/api/v1/admin/backups/{id}` | Get backup details | | ||||||||||||||||||||||||||
| | `DELETE` | `/api/v1/admin/backups/{id}` | Delete a specific backup | | ||||||||||||||||||||||||||
| | `POST` | `/api/v1/admin/backups/restore` | Restore from backup (requires `confirm=true`) | | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| ## Observability and Logging | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| Structured logging pipeline built on **structlog** + stdlib, with automatic sensitive field | ||||||||||||||||||||||||||
| redaction, async-safe correlation tracking, and per-domain log routing. | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| ### Sink Layout | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| Eight default sinks, activated at startup via `bootstrap_logging()`: | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| | Sink | Type | Level | Format | Routes | Description | | ||||||||||||||||||||||||||
| |------|------|-------|--------|--------|-------------| | ||||||||||||||||||||||||||
| | Console | stderr | INFO | Colored text | All loggers | Human-readable development output | | ||||||||||||||||||||||||||
| | `synthorg.log` | File | INFO | JSON | All loggers | Main application log (catch-all) | | ||||||||||||||||||||||||||
| | `audit.log` | File | INFO | JSON | `synthorg.security.*` | Security events only | | ||||||||||||||||||||||||||
| | `errors.log` | File | ERROR | JSON | All loggers | Errors and above only | | ||||||||||||||||||||||||||
| | `agent_activity.log` | File | DEBUG | JSON | `synthorg.engine.*`, `synthorg.core.*` | Agent execution and task lifecycle | | ||||||||||||||||||||||||||
| | `cost_usage.log` | File | INFO | JSON | `synthorg.budget.*`, `synthorg.providers.*` | Cost records and provider calls | | ||||||||||||||||||||||||||
| | `debug.log` | File | DEBUG | JSON | All loggers | Full debug trace (catch-all) | | ||||||||||||||||||||||||||
| | `access.log` | File | INFO | JSON | `synthorg.api.*` | HTTP request/response access log | | ||||||||||||||||||||||||||
|
Comment on lines
+1146
to
+1155
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Narrow Routing 🤖 Prompt for AI Agents |
||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| Logger name routing is implemented via `_LoggerNameFilter` on file handlers. Sinks without | ||||||||||||||||||||||||||
| explicit routing are catch-all (accept all loggers at their configured level). | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| ### Log Directory | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| - **Docker**: `/data/logs/` (under the `synthorg-data` volume, persisted across restarts) | ||||||||||||||||||||||||||
| - **Local dev**: `logs/` relative to working directory (default) | ||||||||||||||||||||||||||
| - **Override**: `SYNTHORG_LOG_DIR` env var | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| ### Rotation | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| File sinks use `RotatingFileHandler` by default (10 MB max, 5 backup files). Alternative: | ||||||||||||||||||||||||||
| `WatchedFileHandler` for external logrotate (`rotation.strategy: external` in config). | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| ### Sensitive Field Redaction | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| The `sanitize_sensitive_fields` processor automatically redacts values for keys matching: | ||||||||||||||||||||||||||
| `password`, `secret`, `token`, `api_key`, `api_secret`, `authorization`, `credential`, | ||||||||||||||||||||||||||
| `private_key`, `bearer`, `session`. Redaction applies at all nesting depths in structured | ||||||||||||||||||||||||||
| log events. Redacted values are replaced with `"**REDACTED**"`. | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| ### Correlation Tracking | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| Three correlation IDs propagated via `contextvars` (async-safe): | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| - **`request_id`**: Bound per HTTP request by `RequestLoggingMiddleware`. Links all log | ||||||||||||||||||||||||||
| events during a single API call. | ||||||||||||||||||||||||||
| - **`task_id`**: Bound per task execution. Links agent activity to a specific task. | ||||||||||||||||||||||||||
| - **`agent_id`**: Bound per agent execution context. | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| All three are automatically injected into every log event by `merge_contextvars` in the | ||||||||||||||||||||||||||
| structlog processor chain. | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| ### Per-Logger Levels | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| Default levels per domain module (overridable via `LogConfig.logger_levels`): | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| | Logger | Default Level | | ||||||||||||||||||||||||||
| |--------|---------------| | ||||||||||||||||||||||||||
| | `synthorg.engine` | DEBUG | | ||||||||||||||||||||||||||
| | `synthorg.memory` | DEBUG | | ||||||||||||||||||||||||||
| | `synthorg.core` | INFO | | ||||||||||||||||||||||||||
| | `synthorg.communication` | INFO | | ||||||||||||||||||||||||||
| | `synthorg.providers` | INFO | | ||||||||||||||||||||||||||
| | `synthorg.budget` | INFO | | ||||||||||||||||||||||||||
| | `synthorg.security` | INFO | | ||||||||||||||||||||||||||
| | `synthorg.tools` | INFO | | ||||||||||||||||||||||||||
| | `synthorg.api` | INFO | | ||||||||||||||||||||||||||
| | `synthorg.cli` | INFO | | ||||||||||||||||||||||||||
| | `synthorg.config` | INFO | | ||||||||||||||||||||||||||
| | `synthorg.templates` | INFO | | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
|
coderabbitai[bot] marked this conversation as resolved.
|
||||||||||||||||||||||||||
| ### Event Taxonomy | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| 50 domain-specific event constant modules under `observability/events/` (one per subsystem: | ||||||||||||||||||||||||||
| api, budget, tool, git, engine, communication, etc.). Every log call uses a typed constant | ||||||||||||||||||||||||||
| (e.g., `API_REQUEST_STARTED`, `BUDGET_RECORD_ADDED`) for consistent, grep-friendly event | ||||||||||||||||||||||||||
| names. Format: `"<domain>.<noun>.<verb>"` (e.g., `"api.request.started"`). | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| ### Uvicorn Integration | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| Uvicorn's default access logger is **disabled** (`access_log=False`, `log_config=None`). | ||||||||||||||||||||||||||
| HTTP access logging is handled by `RequestLoggingMiddleware`, which provides richer structured | ||||||||||||||||||||||||||
| fields (method, path, status_code, duration_ms, request_id) through structlog. Uvicorn's own | ||||||||||||||||||||||||||
| startup/error messages propagate through stdlib's root handler (which structlog wraps via | ||||||||||||||||||||||||||
| `ProcessorFormatter`). | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| ### Docker Logging | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| Two layers of log management: | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| 1. **App-level** (structlog): 8 file sinks with `RotatingFileHandler` (10 MB x 5) writing | ||||||||||||||||||||||||||
| JSON to `/data/logs/`. Console sink writes colored text to stderr. | ||||||||||||||||||||||||||
| 2. **Container-level** (Docker): `json-file` driver with 10 MB x 3 rotation on | ||||||||||||||||||||||||||
| stdout/stderr. Captures console sink output and any uncaught stderr. | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| The layers are complementary -- app files provide structured, routed logs; Docker captures | ||||||||||||||||||||||||||
| the console stream for `docker logs` access. | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| ### Runtime Settings | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| Two observability settings are runtime-editable via `SettingsService`: | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| - `root_log_level` (enum: debug/info/warning/error/critical) -- changes the root logger level | ||||||||||||||||||||||||||
| - `enable_correlation` (boolean) -- toggles correlation ID injection | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| Console sink level can also be overridden via `SYNTHORG_LOG_LEVEL` env var. | ||||||||||||||||||||||||||
|
Comment on lines
+1238
to
+1243
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🧹 Nitpick | 🔵 Trivial Minor: Use em dash for consistency. The documentation uses em dashes ( 📝 Suggested fix - `root_log_level` (enum: debug/info/warning/error/critical) -- changes the root logger level
-- `enable_correlation` (boolean) -- toggles correlation ID injection
+- `root_log_level` (enum: debug/info/warning/error/critical) — changes the root logger level
+- `enable_correlation` (boolean) — toggles correlation ID injection📝 Committable suggestion
Suggested change
🧰 Tools🪛 LanguageTool[typographical] ~1239-~1239: Consider using an em dash (—) instead of ‘--’. (TWO_HYPHENS) 🤖 Prompt for AI Agents |
||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| Full sink CRUD via SettingsService (add/remove/reconfigure sinks at runtime) is planned as a | ||||||||||||||||||||||||||
| future enhancement. | ||||||||||||||||||||||||||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -8,9 +8,10 @@ | |
| import asyncio | ||
| import contextlib | ||
| import os | ||
| import sys | ||
| import time | ||
| from datetime import UTC, datetime | ||
| from pathlib import Path | ||
| from pathlib import Path, PurePath | ||
| from typing import TYPE_CHECKING, Any | ||
|
|
||
| from litestar import Litestar, Router | ||
|
|
@@ -48,13 +49,15 @@ | |
| MeetingOrchestrator, # noqa: TC001 | ||
| ) | ||
| from synthorg.communication.meeting.scheduler import MeetingScheduler # noqa: TC001 | ||
| from synthorg.config import bootstrap_logging | ||
| from synthorg.config.schema import RootConfig | ||
| from synthorg.core.approval import ApprovalItem # noqa: TC001 | ||
| from synthorg.engine.coordination.service import MultiAgentCoordinator # noqa: TC001 | ||
| from synthorg.engine.task_engine import TaskEngine # noqa: TC001 | ||
| from synthorg.hr.performance.tracker import PerformanceTracker # noqa: TC001 | ||
| from synthorg.hr.registry import AgentRegistryService # noqa: TC001 | ||
| from synthorg.observability import get_logger | ||
| from synthorg.observability.config import DEFAULT_SINKS, LogConfig | ||
| from synthorg.observability.events.api import ( | ||
| API_APP_SHUTDOWN, | ||
| API_APP_STARTUP, | ||
|
|
@@ -328,6 +331,57 @@ async def on_shutdown() -> None: | |
| # to code calling get_api_config(), not to the middleware itself. | ||
|
|
||
|
|
||
| def _bootstrap_app_logging(effective_config: RootConfig) -> RootConfig: | ||
| """Activate the structured logging pipeline. | ||
|
|
||
| Applies the ``SYNTHORG_LOG_DIR`` env var override (for Docker | ||
| volume paths) before calling :func:`bootstrap_logging`. | ||
|
|
||
| When the env var is set with an existing logging config, patches | ||
| ``log_dir``. When set without a logging config, creates a | ||
| default config with ``DEFAULT_SINKS``. Otherwise, delegates | ||
| directly to ``bootstrap_logging``. | ||
|
|
||
| Args: | ||
| effective_config: Root config (possibly without a logging | ||
| section). | ||
|
|
||
| Returns: | ||
| The config actually used for logging -- either the original | ||
| ``effective_config`` or a patched copy with the | ||
| ``SYNTHORG_LOG_DIR`` override applied. Callers should use | ||
| the returned value so that ``AppState.config.logging`` | ||
| reflects the active logging configuration. | ||
|
|
||
| Raises: | ||
| ValueError: If ``SYNTHORG_LOG_DIR`` contains ``..`` path | ||
| traversal components. | ||
| """ | ||
| log_dir = os.environ.get("SYNTHORG_LOG_DIR", "").strip() | ||
| if not log_dir: | ||
| bootstrap_logging(effective_config) | ||
| return effective_config | ||
|
|
||
| # Validate before model_copy -- Pydantic validators do not run | ||
| # on model_copy(update=...), so we must check manually. | ||
| if ".." in PurePath(log_dir).parts: | ||
| msg = f"SYNTHORG_LOG_DIR contains '..' path traversal component: {log_dir!r}" | ||
| raise ValueError(msg) | ||
|
|
||
| base_log_cfg = effective_config.logging or LogConfig( | ||
| sinks=DEFAULT_SINKS, | ||
| ) | ||
| patched = effective_config.model_copy( | ||
| update={ | ||
| "logging": base_log_cfg.model_copy( | ||
| update={"log_dir": log_dir}, | ||
| ), | ||
| }, | ||
| ) | ||
| bootstrap_logging(patched) | ||
| return patched | ||
|
|
||
|
|
||
| def create_app( # noqa: PLR0913 | ||
| *, | ||
| config: RootConfig | None = None, | ||
|
|
@@ -371,6 +425,23 @@ def create_app( # noqa: PLR0913 | |
| Configured Litestar application. | ||
| """ | ||
| effective_config = config or RootConfig(company_name="default") | ||
|
|
||
| # Activate the structured logging pipeline (8 sinks) before any | ||
| # other setup so that auto-wiring, persistence, and bus logs all | ||
| # flow through the configured sinks. Respects SYNTHORG_LOG_DIR | ||
| # env var for Docker log directory override. | ||
| try: | ||
| effective_config = _bootstrap_app_logging(effective_config) | ||
| except Exception as exc: | ||
|
Comment on lines
+429
to
+435
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This still leaves observability settings startup-only. The new docs advertise 🤖 Prompt for AI Agents |
||
| print( # noqa: T201 | ||
| f"CRITICAL: Failed to initialise logging pipeline: {exc}. " | ||
| "Check SYNTHORG_LOG_DIR, SYNTHORG_LOG_LEVEL, and the " | ||
| "'logging' section of your config file.", | ||
| file=sys.stderr, | ||
| flush=True, | ||
| ) | ||
| raise | ||
|
|
||
| api_config = effective_config.api | ||
|
|
||
| # Resolve runtime paths for backup service wiring. | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
🧩 Analysis chain
🌐 Web query:
In current uvicorn source (uvicorn/main.py), what value does the CLI pass torun(..., log_config=...)when--log-configis not provided?💡 Result:
When
--log-configis not provided (solog_config is None), the CLI calls:run(..., log_config=LOGGING_CONFIG)— i.e., it passesuvicorn.config.LOGGING_CONFIG. [1]Sources: [1] (raw.githubusercontent.com)
Citations:
Disable Uvicorn's default logging config to match the structured logging pipeline.
The
--no-access-logflag disables only the access logger. However, when--log-configis omitted from the CLI invocation, Uvicorn defaults to applying its standardLOGGING_CONFIGdict, which bypasses the structured logging pipeline. Either pass--log-config /dev/nullto suppress it, or refactor the container startup to calluvicorn.run(log_config=None)directly to ensure all logs route throughRequestLoggingMiddleware.🤖 Prompt for AI Agents