Observability¶

This document is the canonical reference for logging, tracing, and metrics in the GrinSystem API. Read it before instrumenting any new module.

TL;DR¶

• Standard: OpenTelemetry (OTel) for all three pillars — logs, metrics, traces.
• Pipeline: App (OTel SDK + auto-instrumentation) → OTLP/gRPC → local OTel Collector → backend.
• Backend: SigNoz, self-hosted via docker-compose. Same image in dev, qa, and prod.
• Application logging: structlog with two renderers — a custom dev console renderer (purple timestamp · coloured level · event · extras) and a JSONRenderer in qa/prod. The OTel LoggingHandler ships the same records to the Collector in both environments.
• What you write in code: nothing exotic. Bind a module logger with get_logger(__name__), decorate Command/Query handlers with @traced_handler, and use the metric helpers when you need a counter/histogram. The rest is automatic.
• Distributed tracing: the FastAPI auto-instrumentor reads the W3C traceparent request header, so a frontend using the OTel Web SDK propagates its trace into the backend automatically — you see one trace in SigNoz spanning client + server with no glue code on our side.

Why these choices¶

Architecture¶

┌──────────────────────────────────────────────┐
│  FastAPI app (grinsystem-api)                │
│  ┌────────────────────────────────────────┐  │
│  │ OTel SDK                                │  │
│  │  - traces (auto + manual spans)         │  │
│  │  - metrics (auto + business meters)     │  │
│  │  - logs   (structlog → OTel handler)    │  │
│  └─────────────────┬──────────────────────┘  │
│                    │ OTLP/gRPC               │
└────────────────────┼──────────────────────────┘
                     ▼
            ┌────────────────┐         stdout (dev console, pretty)
            │ OTel Collector │ ◀── also receives structlog console output
            └────────┬───────┘
                     │ OTLP
                     ▼
            ┌────────────────┐
            │     SigNoz     │  ← UI at http://localhost:3301
            │ (ClickHouse +  │     traces / logs / metrics / alerts
            │  query svc +   │
            │  frontend)     │
            └────────────────┘

Library inventory¶

Runtime dependencies added to pyproject.toml:

• opentelemetry-sdk
• opentelemetry-exporter-otlp (gRPC OTLP exporter for traces, metrics, logs)
• opentelemetry-instrumentation-fastapi
• opentelemetry-instrumentation-sqlalchemy
• opentelemetry-instrumentation-asyncpg
• opentelemetry-instrumentation-redis
• opentelemetry-instrumentation-httpx
• opentelemetry-instrumentation-logging
• structlog (already present)

All wired once in src/shared/observability/setup.py:configure_observability(), called from create_app() in src/main.py.

Auto-instrumentation matrix¶

You should not need to write manual spans for any of the above. Write a manual span only when you wrap a non-instrumented external boundary, or when an internal business operation needs its own measurable scope (see When to add a manual span below).

Conventions¶

Span naming¶

• Handlers: @traced_handler produces {module}.{handler_class} (e.g. identity.LoginUserHandler).
• Manual spans: {module}.{verb}_{noun} (e.g. manufacturing.calculate_bom_cost).
• Background workers / consumers: {module}.consume_{event_name}.

Span attributes¶

Set automatically: - http.* — method, route, status code (FastAPI auto-instrumentor) - db.* — statement, system (SQLAlchemy / asyncpg auto-instrumentors) - outbox.* — event_type, event_id, aggregate_type (outbox dispatcher CONSUMER span; see § Outbox dispatcher)

Set by the auth dependency once the principal is resolved: - tenant.id, user.id

Set on handler spans by @traced_handler: - app.module, app.handler - app.command or app.query

Add domain attributes (recipe.id, order.id, etc.) only when they help debugging — keep cardinality reasonable.

Structured log keys¶

Bound once and propagated through structlog.contextvars: - tenant_id, user_id — bound by the auth dependency (bind_request_principal) as soon as the principal is resolved - module — bound inside @traced_handler from the handler's package - command or query — bound inside @traced_handler from the input dataclass class name - logger — set automatically when you use get_logger(__name__) - trace_id / span_id — injected by the OTel LoggingInstrumentor on every record

Per-call keys to add as kwargs to logger.info(...): - entity_id — the primary aggregate ID this operation acts on - event — short snake_case event name ("recipe_published", "login_failed")

When to log¶

Do not log on the happy path of every Query Handler — the auto-instrumented HTTP span already records duration and status. Log only domain-relevant state transitions.

When to add a manual span¶

• A handler performs a substantial in-process step worth measuring on its own (e.g. a BOM traversal, a costing calculation, an in-memory batch transform).
• You call an external system the SDK does not instrument (rare; most are covered).
• You want to attach a domain attribute that the auto-span cannot know.

Otherwise rely on auto-instrumentation. More spans ≠ better observability.

When to add a metric¶

Default to none — traces and log queries cover most needs. Add a metric only when: - You need an alertable rate or histogram independent of trace sampling (e.g. outbox_publish_failures_total). - A dashboard graph needs aggregation across millions of events (logs are too expensive at that scale).

Metric naming: grinsystem.{module}.{noun}_{unit} — e.g. grinsystem.manufacturing.production_orders_created_total, grinsystem.identity.login_duration_seconds.

Labels: tenant_id is OK, but never include per-user, per-order, or otherwise high-cardinality IDs.

Outbox dispatcher (GRI-111)¶

The in-process outbox dispatcher (OutboxPoller + EventDispatcher) emits its own span per event and four metrics. The CONSUMER span links the dispatched handler back to the HTTP request that produced the row, so one trace in SigNoz spans HTTP request → handler → outbox row → consume → downstream handler.

Trace linkage¶

OutboxEventPublisher captures the active W3C trace context (traceparent / tracestate) via TraceContextTextMapPropagator().inject(...) and persists it on outbox.trace_context (JSONB) inside the same transaction as the aggregate write. OutboxPoller._dispatch_one extracts that context with the same propagator and starts a shared.consume_<EventType> span (kind CONSUMER) parented on the publisher's span. Rows without a captured context (older rows, non-traced callers) start a fresh root span — extract on an empty mapping never raises.

Span attributes: outbox.event_type, outbox.event_id, outbox.aggregate_type, tenant.id. Per-handler spans are not emitted; per-handler signal lives in the metrics below.

Metrics¶

Label cardinality is bounded: handler is the __qualname__ of a registered callable (one value per on_event registration), error_class is the set of exception classes a handler can raise. Never add tenant_id, event IDs, or aggregate IDs to these labels — use the span attributes for that.

Sensitive data¶

A structlog processor (scrub_sensitive) redacts values for keys matching the configured deny-list before either the console renderer or the OTel handler sees them. Default deny-list:

• password, password_hash, secret, token, access_token, refresh_token, jwt
• authorization, api_key, cookie, set-cookie
• pesel, nip, regon (Polish national IDs — domain-specific)

If you introduce a new sensitive field, add it to the deny-list in src/shared/observability/logging.py in the same PR. Do not rely on call-site discipline.

The OTel SQLAlchemy instrumentation is configured with enable_commenter=False and SQL parameter capture disabled, so query bind values never leave the process.

Dev vs qa/prod¶

Worked example¶

A Command Handler with the full pattern:

# src/modules/identity/application/commands/login_user.py
from dataclasses import dataclass

from src.modules.identity.domain.exceptions import InvalidCredentialsError
from src.modules.identity.domain.repositories.user_repository import UserRepository
from src.shared.observability import counter, get_logger, traced_handler

logger = get_logger(__name__)

login_attempts_total = counter(
    "grinsystem.identity.login_attempts_total",
    description="Login attempts grouped by outcome.",
)


@dataclass
class LoginUserCommand:
    email: str
    password: str
    tenant_id: UUID


@dataclass
class LoginUserResult:
    user_id: UUID
    access_token: str


class LoginUserHandler:
    def __init__(self, user_repo: UserRepository) -> None:
        self._user_repo = user_repo

    @traced_handler
    async def handle(self, command: LoginUserCommand) -> LoginUserResult:
        user = await self._user_repo.get_by_email(command.email, command.tenant_id)
        if user is None or not user.verify_password(command.password):
            login_attempts_total.add(1, {"outcome": "rejected"})
            logger.warning("login_failed", email=command.email)
            raise InvalidCredentialsError()

        token = user.issue_access_token()
        login_attempts_total.add(1, {"outcome": "accepted"})
        logger.info("login_succeeded", event="user_logged_in", entity_id=str(user.id))
        return LoginUserResult(user_id=user.id, access_token=token)

What SigNoz shows for one request:

1. HTTP span POST /api/v1/auth/login with tenant.id, user.id.
2. Handler span identity.LoginUserHandler as a child, with app.command=LoginUserCommand.
3. SQL spans under the handler span for the users lookup.
4. Log records correlated by trace_id — login_failed (warning) or login_succeeded (info), carrying logger=src.modules.identity.application.commands.login_user.
5. Metric grinsystem.identity.login_attempts_total{outcome=...} queryable in the metrics view, alertable from the alerts panel.

If the request originated from an OTel-instrumented frontend, the HTTP span is itself a child of a browser-side span and the whole flow renders as a single trace in SigNoz.

Local usage¶

make up                # brings up app + Postgres + Redis + SigNoz + Collector
open http://localhost:3301    # SigNoz UI
make observability-down       # stop only the observability stack
make observability-up         # start only the observability stack

Dev console output is preserved — running uvicorn (or make logs) shows colourised structlog lines whose trace_id matches the trace in SigNoz.

See also¶

• docs/architecture/conventions.md § Observability — code-level conventions and snippets in the Command/Query Handler templates.
• docs/architecture/hld.md — system overview.
• src/shared/observability/ — implementation.