Logging

Suprnova logs through tracing - every log line is a structured event with fields, not a formatted string. A subscriber is installed at boot that reads LOG_LEVEL and LOG_FORMAT from the environment, emits pretty multi-line output in dev and one JSON object per line in production, and propagates a per-request id into every event a handler emits.

This chapter covers the log surface itself: the subscriber, the formats, the levels, and the request-id correlation that makes a production log searchable. For the OpenTelemetry bridge and query logging see Observability; for the request Context bag that emitters can read alongside the id see Context.

What gets logged where

Two outputs by default:

The dev/prod default is computed from APP_ENV via Environment::detect(). Override with LOG_FORMAT=pretty or LOG_FORMAT=json to force one explicitly.

# .env (dev)
LOG_LEVEL=info,sqlx=warn
LOG_FORMAT=pretty   # optional; this is the dev default

# .env.production
LOG_LEVEL=info,sqlx=warn,suprnova::queue=debug
LOG_FORMAT=json     # optional; this is the prod default

The framework only writes to stdout. In production point your container runtime, systemd journal, or log aggregator at it (docker logs, kubectl logs, journalctl -u my-app, a Loki/Vector agent, etc.). There is no rotating file appender - let the platform own log persistence.

Emitting events

Use the tracing macros in handlers, jobs, middleware, anywhere:

use suprnova::{json_response, session, Request, Response};
use tracing::{debug, info, warn, error, instrument};

pub async fn checkout(_req: Request) -> Response {
    let user_id: i64 = session()
        .and_then(|s| s.get::<i64>("user_id"))
        .unwrap_or(0);

    info!(user_id, "checkout starting");

    let order = place_order(user_id).await.map_err(|e| {
        error!(user_id, error = %e, "checkout failed");
        e
    })?;

    info!(user_id, order_id = order.id, total = order.total_cents, "checkout succeeded");

    json_response!(order)
}

Each field becomes a top-level key in JSON output and a coloured field=value pair in pretty output. Prefer fields over interpolation - they're searchable in JSON logs and the formatter handles type-aware rendering.

To wrap a function in a span and stamp every event inside it with shared fields, use #[instrument]:

#[instrument(skip(db), fields(user_id = %user_id))]
pub async fn load_dashboard(
    db: &suprnova::DatabaseConnection,
    user_id: i64,
) -> Result<Dashboard, FrameworkError> {
    info!("loading"); // automatically carries user_id from the span
    // … queries …
}

The same #[instrument] becomes an OpenTelemetry span when the otel feature is enabled - see Observability.

Log levels

LOG_LEVEL is a tracing-subscriber env-filter directive, not a single level. The grammar is comma-separated target=level pairs, where bare values set the default:

LOG_LEVEL=info                                  # everything at info+
LOG_LEVEL=debug                                 # everything at debug+
LOG_LEVEL=info,sqlx=warn                        # info default, sqlx quieter
LOG_LEVEL=warn,suprnova::queue=debug,my_app=info  # warn default, two targets verbose

Targets are usually the emitting crate or module path (suprnova::queue, hyper::server, my_app::services::checkout). Find a target by reading the JSON log line - the target field on every event is its filter key.

Levels in increasing verbosity: error < warn < info (default) < debug < trace. The wire-format error response is always sanitised to {"message": "Internal Server Error"} regardless of level - the detail goes only to the structured log.

Invalid directives don't crash boot

A malformed LOG_LEVEL (e.g. LOG_LEVEL=app=notalevel) falls back to "info" and writes a one-line warning to stderr:

suprnova: invalid LOG_LEVEL directive "app=notalevel" (...); falling back to "info". Fix LOG_LEVEL to silence this.

This is stderr rather than tracing::warn! because the subscriber hasn't been installed yet - a warn! would be silently dropped. Fix the directive and the warning goes away.

Pretty vs JSON output

The same info!(user_id = 42, "saved") renders differently per format.

Pretty (dev):

  2026-05-30T22:14:08.221341Z  INFO request{request_id=78a9...} my_app::handlers::checkout: saved
    at src/handlers/checkout.rs:48
    in checkout
    in request with request_id: 78a9..., method: POST, path: /checkout

JSON (prod):

{
  "timestamp": "2026-05-30T22:14:08.221341Z",
  "level": "INFO",
  "fields": { "message": "saved", "user_id": 42 },
  "target": "my_app::handlers::checkout",
  "span": { "name": "checkout" },
  "spans": [
    { "name": "request", "request_id": "78a9...", "method": "POST", "path": "/checkout" }
  ]
}

The JSON shape is what production aggregators (Datadog, Loki, Honeycomb, CloudWatch, …) parse out of the box. span.request_id is the correlation key - see below.

Per-request id correlation

Every HTTP request gets a RequestId from RequestIdMiddleware, the outermost middleware on every chain. The id is:

• Reused from a safe inbound X-Request-Id header (alphanumerics plus - _ . :, up to 128 bytes), or freshly minted as a UUID v4 if absent / unsafe.
• Echoed back on the response as X-Request-Id (both 2xx and 5xx variants).
• Scoped into a request tracing span so every event from any middleware, handler, or downstream library carries request_id in its spans array automatically.
• Seeded into the request Context bag as _request_id, so emitters that want the bare string (jobs, broadcast payloads, error reports) can read it by name.

Read it in code with current_request_id():

use suprnova::current_request_id;
use tracing::info;

if let Some(id) = current_request_id() {
    info!(request_id = %id, "checkpoint reached");
}

current_request_id() returns Option<RequestId> because background work (jobs, scheduled tasks, tests that didn't install the middleware) runs outside any request scope.

Background tasks: spawn with the id

tokio::spawn starts a fresh task with empty task-locals - a handler that spawns side-effect work loses current_request_id() and its log events become orphaned. Use spawn_with_request_id instead:

use suprnova::spawn_with_request_id;
use tracing::info;

pub async fn checkout(req: suprnova::Request) -> suprnova::Response {
    let order = place_order().await?;

    spawn_with_request_id(async move {
        // This task still observes current_request_id().
        // Its log events carry the same request_id as the handler's.
        info!(order_id = order.id, "post-checkout fanout running");
        send_receipt(order.id).await;
        update_analytics(order.id).await;
    });

    suprnova::Response::ok().json(&order)
}

The helper propagates both the RequestId task-local and the current tracing::Span, so the spawned future's events nest under the same request span in the log. Outside an active request scope it falls through to a bare tokio::spawn - safe to use unconditionally.

Only the request id and tracing span follow the task - the request Context bag deliberately does not, because background work isn't serving the originating HTTP request.

The subscriber

The framework installs a global tracing subscriber at boot from Server::run(). You almost never call this yourself; it's documented because tests, embedders, and unusual entry points sometimes need to.

use suprnova::{LogConfig, init_subscriber};

// Read LOG_LEVEL / LOG_FORMAT from the environment:
init_subscriber(LogConfig::from_env());

// Or programmatic:
init_subscriber(LogConfig {
    level: "info,sqlx=warn".to_string(),
    format: suprnova::LogFormat::Json,
});

init_subscriber is idempotent. A second call leaves the existing subscriber in place and emits a tracing::warn! so an operator can see that the new LogConfig was not applied. This is what lets tests that each call init_subscriber not race each other - the first wins, the rest are no-ops.

For the OTel-aware variant (the same LogConfig, plus distributed-tracing export), use init_telemetry.

The daemons

queue:work, schedule:work, schedule:run and workflow:work are subcommands of your app binary and do not boot through Server::run(), so they install their own subscriber on the way up. They read the same LOG_LEVEL and LOG_FORMAT as the server, and you call nothing yourself:

LOG_LEVEL=info,suprnova::queue=debug cargo run --bin my-app -- queue:work

# …or, in a container, against the built binary:
LOG_LEVEL=info my-app queue:work

Before 0.9.1 that path installed nothing at all. Every tracing:: line the daemons emit went nowhere and LOG_LEVEL was inert for them, which in a container left the startup banner as the only output - a worker dead-lettering jobs, a scheduler skipping a tick it lost the election for, and a lock it could not release all looked identical to an idle process. If you are running a pinned build older than 0.9.1 and wondering why a worker says nothing, that is why, and the fix is the upgrade rather than a configuration change.

Most of what a worker has to say it says at warn! and error! - a job exhausting its attempts, a dead-letter it could not persist, a lock it could not release - so the default info level is enough to see trouble. Drop to debug when you need the quieter decisions as well.

Tests

Tests don't need to install a subscriber - the #[suprnova_test] attribute and TestContainer::fake set up enough machinery for handler events to flow. If you want to assert on log output, capture via tracing-subscriber's tracing_subscriber::fmt::TestWriter or a custom layer; the framework deliberately does not ship a "capture all logs in this test" fake because the standard tracing-subscriber test patterns work cleanly.

Why Suprnova diverges

Laravel uses Monolog - message strings with optional context arrays, log channels, and per-channel handlers (file, syslog, Slack, …). PHP's request-per-process model means a single global static logger is safe: each request gets its own process and its own context.

Rust's process model is the opposite - one process serves many concurrent requests on many threads. A global string-formatter would race on context and require explicit request_id plumbing through every call site. tracing solves both with structured fields and task-local spans: no plumbing, fields stay typed, and correlation is automatic because the request span is in scope for every event the chain emits.

stdout-only output is also intentional. In containerised deployments (the only way Suprnova ships) the runtime, not the app, owns log persistence - file rotation, retention, and shipping all belong to the platform.

Next

• Observability - OpenTelemetry, query log, the full operator surface
• Context - the per-request bag where _request_id and other contextual fields live
• Error Handling - how the framework's panic boundary and 5xx path emit their own structured events
• Environment Variables - LOG_LEVEL, LOG_FORMAT reference