8.4 Что видел сервер

Работа без отчёта - хорошая работа, пока она хорошая. Ответа “всё в порядке” достаточно ровно до тех пор, пока это правда. Потом приходит запрос, который вёл себя странно, - и хочется знать, что видел сервер. Он видел. Он просто не говорил.

Что нужно

Можно написать println!("task added: id={id} title={title}") - и это сработает. Вывод будет таким:

task added: id=3 title=buy coffee

tracing с одной строкой инициализации даёт:

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

Временна́я метка, уровень (INFO, WARN, …) и имя модуля - бесплатно, без форматирования вручную. Именованные поля (id=3, title="buy coffee") добавляются через синтаксис макроса, а не конкатенацией строк. tracing-subscriber отвечает за то, куда и в каком виде это выводится.

Постройка

В crates/api/Cargo.toml добавляем две строки:

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

В начало main в crates/api/src/main.rs - инициализация и строка при старте:

tracing_subscriber::fmt::init();
// ... конфиг, стор, роутер ...
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() - сокращение для стандартной конфигурации: вывод в stdout, одна строка на запись, с временной меткой и именем модуля.

В crates/api/src/routes.rs добавляем вызовы в обработчики.

В add - после успешного добавления, когда уже есть id:

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 - поле с именем id и значением одноимённой переменной. title = %req.title - форматирование через Display (префикс %). Без префикса используется Debug.

В list - в начале:

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())
}

В get_task и done у запроса два исхода: нашли - info, не нашли - warn. Уровень warn говорит “что-то неожиданное, но обработанное”:

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)
        }
    }
}

Результат

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

В другом терминале:

$ 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

В первом терминале:

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

Успешный запрос - INFO. Запрос к несуществующей задаче - WARN. Уровень в записи несёт смысл, а не только отметку о факте.

Полный код tq для этой главы - 8-ready/04-what-the-server-saw/.

Lore: map_err с блоком

В реальных проектах обработчики get_task и done чаще пишут через map_err с блочным замыканием - без 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()))

Замыкание |_| { ... } работает как блок: несколько выражений, последнее без ; - возвращаемое значение. Это тот же принцип, что и у любого блока в Rust.

Lore: stdout или stderr

fmt::init() пишет в stdout. Для серверов чаще используют stderr - stdout остаётся чистым для данных, stderr для диагностики. За fmt::init() скрывается строитель:

tracing_subscriber::fmt()
    .with_writer(std::io::stderr()) // вывод в stderr
    .without_time()                 // без временной метки
    .init();

Это иллюстрация возможностей строителя, не шаблон для продакшна. В реальных проектах конфигурацию tracing-subscriber обычно диктует платформа или команда - fmt::init() достаточно до тех пор, пока не появится конкретная причина менять.

Lore: RUST_LOG

Пять уровней - trace, debug, info, warn, error - образуют шкалу от “очень подробно” до “только критическое”. По умолчанию fmt::init() показывает info и выше. Переменная окружения RUST_LOG меняет порог:

RUST_LOG=debug make serve   # debug и выше
RUST_LOG=warn make serve    # только warn и error

debug! и trace! полезны при отладке конкретной проблемы - в продакшне их отключают, чтобы не заполнять вывод деталями нормальной работы.