← Table of contents

8.4 What the Server Saw

Work without a report is good work, so long as it is good. “Everything is fine” is enough of an answer right up until it isn’t. Then comes a request that behaved strangely - and you want to know what the server saw. It saw. It simply did not say.

What You Need

You could write println!("task added: id={id} title={title}") - and it would work. The output would look like this:

task added: id=3 title=buy coffee

tracing with one initialization line gives:

2026-06-24T10:12:05Z  INFO tq_api::routes: task added id=3 title="buy coffee"

Timestamp, level (INFO, WARN, …), and module name - free, no manual formatting. Named fields (id=3, title="buy coffee") are added through macro syntax, not string concatenation. tracing-subscriber controls where and in what form the output goes.

The Build

Two lines in crates/api/Cargo.toml:

tracing = "0.1"
tracing-subscriber = "0.3"

At the top of main in crates/api/src/main.rs - initialization and a startup line:

tracing_subscriber::fmt::init();
// ... config, store, router ...
let listener = tokio::net::TcpListener::bind("0.0.0.0:3000").await.unwrap();
tracing::info!("listening on 0.0.0.0:3000");
axum::serve(listener, app).await.unwrap();

tracing_subscriber::fmt::init() is a shorthand for the standard configuration: output to stdout, one line per record, with timestamp and module name.

In crates/api/src/routes.rs, calls are added to the handlers.

In add - after a successful add, once id is known:

async fn add(State(state): State<AppState>, Json(req): Json<AddRequest>) -> Result<Json<Task>, ApiError> {
    let mut guard = state.store.lock().unwrap();
    let id = guard.add(req.title.as_str()).map_err(|e| ApiError::BadRequest(e.to_string()))?;
    persistence::save(guard.all(), &state.data_path).unwrap();
    tracing::info!(id = id, title = %req.title, "task added");
    Ok(Json(guard.get(id).unwrap().clone()))
}

id = id - a field named id with the value of the same-named variable. title = %req.title

In list - at the top:

async fn list(State(state): State<AppState>) -> Json<Vec<Task>> {
    tracing::info!("list tasks");
    let guard = state.store.lock().unwrap();
    Json(guard.all().to_vec())
}

In get_task and done a request has two outcomes: found - info, not found - warn. The warn level means “something unexpected, but handled”:

async fn get_task(State(state): State<AppState>, Path(id): Path<u64>) -> Result<Json<Task>, ApiError> {
    let guard = state.store.lock().unwrap();
    match guard.get(id) {
        Ok(task) => {
            tracing::info!(id = id, "get task");
            Ok(Json(task.clone()))
        }
        Err(_) => {
            tracing::warn!(id = id, "task not found");
            Err(ApiError::NotFound)
        }
    }
}

async fn done(State(state): State<AppState>, Path(id): Path<u64>) -> Result<Json<Task>, ApiError> {
    let mut guard = state.store.lock().unwrap();
    match guard.get_mut(id) {
        Ok(task) => {
            task.complete();
            let task = task.clone();
            persistence::save(guard.all(), &state.data_path).unwrap();
            tracing::info!(id = id, "task marked done");
            Ok(Json(task))
        }
        Err(_) => {
            tracing::warn!(id = id, "task not found");
            Err(ApiError::NotFound)
        }
    }
}

The Result

$ make serve
2026-06-24T10:12:01.000Z  INFO tq_api: listening on 0.0.0.0:3000

In another terminal:

$ curl -s -w "\ncode: %{http_code}\n" -X POST localhost:3000/tasks \
  -H "Content-Type: application/json" -d '{"title":"buy coffee"}'
{"id":3,...}
code: 200

$ curl -s -w "\ncode: %{http_code}\n" localhost:3000/tasks/99
not found
code: 404

In the first terminal:

2026-06-24T10:12:05.123Z  INFO tq_api::routes: task added id=3 title="buy coffee"
2026-06-24T10:12:08.789Z  WARN tq_api::routes: task not found id=99

A successful request - INFO. A request for a nonexistent task - WARN. The level in the record carries meaning, not just a note that something happened.

The complete tq code for this chapter is in 8-ready/04-what-the-server-saw/.

Lore: map_err with a Block

In real projects, get_task and done are more often written with map_err and a block closure - without match:

let task = guard.get(id).map_err(|_| {
    tracing::warn!(id = id, "task not found");
    ApiError::NotFound
})?;
tracing::info!(id = id, "get task");
Ok(Json(task.clone()))

The closure |_| { ... } works like a block: multiple expressions, the last one without ; is the return value. This is the same principle as any block in Rust.

Lore: stdout or stderr

fmt::init() writes to stdout. For servers, stderr is more common - stdout stays clean for data, stderr for diagnostics. Behind fmt::init() hides a builder:

tracing_subscriber::fmt()
    .with_writer(std::io::stderr()) // write to stderr
    .without_time()                 // no timestamp
    .init();

This is an illustration of the builder’s options, not a production template. In real projects, tracing-subscriber configuration is usually dictated by the platform or team - fmt::init() is enough until there is a concrete reason to change it.

Lore: RUST_LOG

Five levels - trace, debug, info, warn, error - form a scale from “very detailed” to “critical only”. By default fmt::init() shows info and above. The RUST_LOG environment variable changes the threshold:

RUST_LOG=debug make serve   # debug and above
RUST_LOG=warn make serve    # warn and error only

debug! and trace! are useful when debugging a specific problem - in production they are turned off to avoid filling the output with details of normal operation.