Three layers of operator-visible signal ship in the framework: structured
logs (always on), per-request id correlation (always on, propagates into
spawned tasks), and an opt-in OpenTelemetry bridge that turns every
tracing span into an exported OTel span. The same #[tracing::instrument]
you'd write for local logs becomes a distributed-trace span when the OTel
feature is on - no second instrumentation API.
use ;
use LogConfig;
async
A scaffolded app's Server already calls init_telemetry for you and
flushes the guard on the shutdown signal - you only wire it by hand when
embedding Suprnova in your own runtime.
The three layers
| Layer | Always on | What it gives you |
|---|---|---|
Structured logging (tracing) |
Yes | Stdout logs in pretty (dev) or json (production) format, environment-aware |
| Request-id correlation | Yes | Per-request id scoped through a tokio::task_local!, echoed on X-Request-Id, propagates into spawn_with_request_id tasks |
| OpenTelemetry export | otel feature + collector endpoint |
OTLP HTTP/proto export of traces, metrics, and logs; W3C traceparent propagation both ways |
The OTel layer is opt-in at compile time so default builds carry no
OpenTelemetry dependencies and the Metrics facade compiles to
inert no-ops. With the feature off, "trace" and "metric export" silently
become no-ops - your logs still work.
Why Suprnova diverges
Laravel's observability story splits between in-framework events
(QueryExecuted, MessageSent, JobProcessed) and runtime concerns
delegated to PHP extensions (OpenTelemetry, Sentry, New Relic) plugged in
at the FPM layer. The event surface is rich; the runtime surface is
"install the extension your APM vendor needs."
Suprnova is a single async process, so it owns both halves. The event
surface is parity (same QueryExecuted/NotificationSent/ErrorOccurred
shape), and the runtime surface is a tracing → OpenTelemetry bridge
inside the framework. You don't install an extension; you flip a feature
flag and the same spans you already emit become OTel-exported.
Structured logging
LogConfig::from_env() reads two env vars:
| Var | Default | Notes |
|---|---|---|
LOG_LEVEL |
"info" |
tracing-subscriber env-filter syntax (e.g. "debug,sqlx=warn,hyper=warn") |
LOG_FORMAT |
environment-aware | "json" in production, "pretty" everywhere else; explicit value always wins |
The format default is detected from APP_ENV via Environment::detect():
a production deploy gets one-JSON-object-per-line output for log
aggregators by default, local/dev runs get human-readable multi-line
output. An explicit LOG_FORMAT=pretty will override the production
default if you want raw stdout in production.
# Local dev - explicit overrides win
LOG_LEVEL=debug,sqlx=warn,hyper=warn LOG_FORMAT=pretty
# Production - APP_ENV=production flips the format default to json
APP_ENV=production LOG_LEVEL=info
A malformed LOG_LEVEL directive does not crash boot - it falls back to
"info" and prints a one-line warning on stderr so the misconfiguration
is operator-visible.
Span context in every line
Every routed HTTP request runs inside a request span created by the
framework's outermost middleware. The span carries three fields -
request_id, method, path - and the JSON formatter nests them under
span on every event emitted inside the request. Your application code
doesn't need to read or record the id on every line; the span carries it
implicitly:
use info;
pub async
Request-id correlation
Every request gets a 36-character lowercase UUID v4 id, scoped through a
tokio::task_local!. The middleware reuses an inbound X-Request-Id
when the header value passes a strict safety check (ASCII alphanumeric
plus -_.:, max 128 bytes); anything outside that charset is rejected
and replaced with a fresh UUID so an attacker cannot inject control
characters into log output or balloon downstream pipelines.
The same id is echoed on every response - success, error, and panic
recovery - as the X-Request-Id header, so a frontend or upstream
service can include it in bug reports and operators can grep for it in
the structured log.
Reading the id
use ;
pub async
current_request_id() returns None outside a request - background
jobs, scheduled tasks, and tests without the middleware see no id, and
the helper does not invent one. spawn_with_request_id outside a
request scope is exactly tokio::spawn; nothing magical happens.
Where the id is also available
| Surface | How |
|---|---|
tracing events |
span.request_id on every line inside the request |
| Response header | X-Request-Id on success, error, and panic-recovered responses |
Context bag |
Context::get("_request_id") - readable from observers, listeners, jobs that consult Context |
| Spawned tasks | current_request_id() after spawn_with_request_id |
Built-in events for observability
The framework dispatches typed events at the points an operator usually
wants to instrument. Each is a suprnova::Event you can listen for via
EventFacade::listen::<E, _>(...) and ship to Sentry, Datadog, Slack, or
your metrics pipeline. All of them run through dispatch_best_effort, so
a failing listener does not break the request that triggered it.
| Event | When it fires | Carries |
|---|---|---|
ErrorOccurred |
Any FrameworkError → 5xx conversion (including panic recovery) |
error context + request id |
QueryExecuted |
Every query routed through the instrumented executor helpers | sql, bindings, duration, connection, read/write classification, result |
ConnectionEstablished |
DbConnection::connect succeeded |
connection name |
TransactionBeginning / TransactionCommitted / TransactionRolledBack |
Closure-form DB::transaction + manual handles |
connection name |
NotificationSending / NotificationSent / NotificationFailed |
Per-channel before/after/error of Notification::send |
notification + channel + recipient |
ErrorOccurred is the hook for shipping 5xx exceptions; QueryExecuted
is the hook for slow-query alerts; the notification trio is the hook for
delivery dashboards. See Events for the listener API and
Lifecycle for where in the request path each event fires.
Direct DB query observation
DB::listen is a second, synchronous hook tailored specifically for
QueryExecuted. It fires inline inside the executor, so a slow listener
slows the query - keep it light. The dispatcher path
(EventFacade::listen::<QueryExecuted, _>) is run-them-all
best-effort and tolerates errors; prefer it for anything that can fail.
use DB;
// In bootstrap.rs:
DBlisten?;
A listener that itself issues a database query will not re-fire
QueryExecuted for the nested call - a task-local re-entrancy guard
prevents the "log-to-DB listener → emits event → log-to-DB → ..." loop.
Capturing a query log for tests / debug
For test assertions or one-off "what ran during this block?" debugging:
use DB;
DBenable_query_log?;
// ... run the code you want to inspect ...
let queries = DBget_query_log?;
for q in &queries
DBdisable_query_log?;
DBflush_query_log?;
The buffer is unbounded - every captured query grows it. Use it for tests and one-shot investigation, flush periodically if you leave it on in production.
Distributed tracing (OTel)
Add the otel feature to opt in:
[dependencies]
suprnova = { git = "...", features = ["otel"] }
Configure via the standard OTel environment variables:
# Minimum: where the collector lives.
OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4318
OTEL_SERVICE_NAME=my-app # defaults to "suprnova"
OTEL_SERVICE_VERSION=1.4.2 # defaults to your crate version
Telemetry is enabled only when OTEL_EXPORTER_OTLP_ENDPOINT is set
and the kill switch OTEL_SDK_DISABLED is not on. With no endpoint
the logging layer runs alone, and the returned guard holds no providers,
so dropping it without shutdown() is silent (no spurious "buffered
telemetry may be lost" warning on every test process).
Trace context joins automatically
Inbound. When a request arrives carrying a W3C
traceparent header - i.e. it
was made by another traced service - the middleware extracts that
context and reparents the request span onto the caller's span. Your
server span shows up as a child in the same distributed trace, not a
fresh root. A request without traceparent (a direct browser hit) stays
a clean root span.
Outbound. The framework HTTP client (Http)
injects the active trace context as traceparent on every outbound
call, so the downstream service continues the same trace.
Together: upstream service → your handler → downstream service is one
connected trace, with no manual span plumbing in your handlers.
Error status. When a handler returns a 5xx, the request span is
marked errored so the OTel backend shows Status::Error. (A handler
panic is caught and turned into a 500 with an error-level log and an
ErrorOccurred event, but the OTel span status is not set on that path -
the panic unwinds the span's future before the marker runs.)
Adding your own spans
Because the bridge turns every tracing span into an OTel span, you
instrument with plain tracing - no OTel-specific API in your code:
use DatabaseConnection;
async
Environment variables Suprnova reads
| Var | Effect |
|---|---|
OTEL_EXPORTER_OTLP_ENDPOINT |
Collector base URL. Unset → telemetry disabled. |
OTEL_SERVICE_NAME |
service.name resource attribute (default "suprnova"). |
OTEL_SERVICE_VERSION |
service.version resource attribute (default: crate version). |
OTEL_SDK_DISABLED |
Kill switch. Case-insensitive true or 1 disables export even with an endpoint set. |
The rest of the standard OTLP knobs are read by the SDK itself, so configure them the normal way:
| Var | Read by |
|---|---|
OTEL_EXPORTER_OTLP_HEADERS |
exporter (collector auth, e.g. Authorization=Bearer ...) |
OTEL_EXPORTER_OTLP_PROTOCOL |
exporter (http/protobuf, etc.) |
OTEL_EXPORTER_OTLP_TIMEOUT |
exporter |
OTEL_EXPORTER_OTLP_COMPRESSION |
exporter |
Per-signal endpoint overrides (OTEL_EXPORTER_OTLP_TRACES_ENDPOINT,
_METRICS_ENDPOINT, _LOGS_ENDPOINT) are currently shadowed by the
base endpoint - all three signals go to OTEL_EXPORTER_OTLP_ENDPOINT.
If you need to fan signals to different collectors, run a local
collector that routes them.
Metrics
Metrics is the facade for counters, histograms, and gauges. Handles
are cheap to clone and resolve the global meter on each construction:
use Metrics;
// Counter - monotonic.
let signups = counter;
signups.inc; // +1
signups.inc_by; // +3
signups.inc_with; // +1 with a label
// Histogram - distributions (latency, sizes).
let latency = histogram;
latency.record;
latency.record_with;
// Gauge - point-in-time value.
let queue_depth = gauge;
queue_depth.set;
queue_depth.set_with;
Without the otel feature every call above is a no-op with zero
allocation - leave instrumentation in hot paths and pay nothing in
default builds.
Metric handles bind to whichever meter provider is active when the
underlying instrument is first resolved. Create handles after
init_telemetry has run (or lazily at first use) - a handle constructed
before initialization resolves against the no-op provider and stays
inert. The idiomatic pattern is a once_cell / LazyLock handle
resolved on first emit, well after boot.
Attribute values are string-typed (&[(&'static str, &str)]). Numeric
and boolean attributes are a planned enhancement; format them as strings
at the call site for now.
Naming: stable, ASCII, dot-delimited (e.g. "http.requests.total",
"http.request.duration"). The standard OTel semantic conventions live
in opentelemetry-semantic-conventions::metric::*.
The shutdown contract
init_telemetry returns a TelemetryGuard that owns the SDK provider
handles. The OTel batch processors buffer spans / metrics / logs in
memory and flush asynchronously, so you must guard.shutdown().await
before the process exits or you lose whatever is still buffered.
- Calling
shutdown()flushes and is safe to call once (it takesself). - Dropping the guard without
shutdown()logs a warning - but only when the guard actually holds providers. A telemetry-disabled run (no endpoint, orOTEL_SDK_DISABLED, or a non-otelbuild) hands back a provider-less guard whose drop is silent, so collector-less dev and test runs don't get spammed.
Summary
| Task | API |
|---|---|
| Enable OTel | features = ["otel"] + OTEL_EXPORTER_OTLP_ENDPOINT |
| Initialize | init_telemetry(LogConfig::from_env(), OtelConfig::from_env()) |
| Flush on exit | guard.shutdown().await |
| Disable at runtime | OTEL_SDK_DISABLED=true |
| Custom span | #[tracing::instrument] (auto-bridged to OTel) |
| Counter / histogram / gauge | Metrics::counter/histogram/gauge(name) |
| Distributed trace join | Automatic - inbound traceparent extracted, outbound injected |
| Read current request id | current_request_id() |
| Propagate id into spawn | spawn_with_request_id(future) |
| Synchronous query observer | `DB::listen( |
| Best-effort query observer | EventFacade::listen::<QueryExecuted, _>(...) |
| Capture queries for tests | DB::enable_query_log() → DB::get_query_log() |
Next
- Events - listener API, dispatch modes,
EventFacade::fake()for tests - Lifecycle - where in the request path each event fires and where the request span is constructed
- Error Handling -
ErrorOccurred,HttpError, sanitised 5xx bodies - Database -
QueryExecuted,DB::transaction, the executor helpers that fire the events - HTTP Client - outbound
traceparentinjection that closes the distributed-trace loop
