Диагностика HTTP-вызовов клиента

1. Диагностика, даже если «и так работает»

Когда вы пишете консольную программу, часто хватает фразы «готово» и пары println(). Но внешние HTTP-вызовы живут в мире, где «у меня не работает» может означать десять разных причин — от «у тебя нет интернета» до «провайдер вернул 500», от «ты не так собрал URI» до «JSON изменился, и Jackson не смог распарсить ответ». Если в этот момент у вас нет хотя бы минимальной диагностики, вы превращаетесь в археолога: копаете вслепую, по косвенным следам, с молитвой «пусть оно само починится».

Важно понимать: диагностика — это не «много текста в консоли». Это короткие факты, которые позволяют быстро ответить на простой набор вопросов. В идеале вы хотите посмотреть на 2–3 строки и сразу понять, что произошло. А ещё вы хотите, чтобы эти строки были одинаковыми по форме, иначе на десятом запросе консоль превращается в роман «Война и мир», где вы не можете найти даже главного героя.

И да, сейчас мы будем использовать простые System.out/System.err. Это нормально для стадии курса, где мы осознанно учимся руками и видим механику. Позже мы заменим этот вывод на нормальный logging stack, но если вы не умеете сформулировать «что логировать», то никакой логгер вас не спасёт — он просто будет красиво печатать бессмысленные сообщения.

Команды уже умеют запускать catalog search и catalog details. Но как только вызов становится живым HTTP-запросом, одного happy-path мало: нужно быстро отличить «не туда сходили», «сеть не ответила» и «JSON не совпал», не смешав эти детали с обычным выводом команды.

Два потока текста: пользовательский вывод vs диагностический вывод

В этом месте обычно происходит тихая трагедия: программа печатает «Найдено 5 книг», и вроде бы всё хорошо, но когда что-то ломается — туда же вперемешку падают технические сообщения. Получается каша: пользователю показываем одно, а сами пытаемся дебажить другое, и всё в одном месте. Очень быстро появляется желание «просто всё закомментировать и снова включить по очереди». Это не инженерный подход, это магия в стиле «шаманим, пока не заведётся».

Мы будем держать в голове простое разделение: пользовательский вывод — то, что человек ожидает увидеть как результат команды (catalog search, catalog details). Это обычно идёт в System.out. Диагностический вывод — то, что помогает нам понять, как команда выполнялась технически: целевой URI, статус, длительность, тип ошибки. Это удобнее печатать в System.err, потому что stderr исторически используется именно для «служебных сообщений».

Так вы сможете даже визуально отличать одно от другого: пользовательская часть — спокойная и «про результат», диагностическая — короткая и «про факты выполнения». А если однажды вы будете запускать программу в терминале и перенаправлять вывод в файл, разделение stdout/stderr внезапно станет очень полезным: результаты можно сохранять отдельно от диагностики.

2. Формула диагностики: 5 фактов в строке

Диагностическое сообщение полезно не потому, что оно умное, а потому, что оно отвечает на понятные вопросы. Здесь удобно зафиксировать «минимальную формулу»: операция, режим, куда идём, чем закончилось, сколько заняло. Если в сообщении нет хотя бы двух из этих вещей — оно часто превращается в шум. Если есть все пять — сообщение обычно уже можно читать «как логи взрослого сервиса», даже если мы печатаем его просто в консоль.

Ниже — таблица, которая помогает держать формат в голове (и не изобретать его заново в каждом методе):

Давайте сразу договоримся про стиль строки. Хорошо работает формат «одно сообщение — одна строка, ключи через key=value». Во-первых, это легко читать глазами. Во-вторых, потом легко искать по тексту (даже обычным Ctrl+F). Например, такие строки:

DIAG catalog.search mode=real uri=https://openlibrary.org/search.json?q=clean%20code
DIAG catalog.search result=ok status=200 durationMs=147

Обратите внимание: мы не печатаем raw JSON, не печатаем двадцать строк «я здесь, я там». Мы печатаем факты, которые помогают восстановить историю выполнения запроса.

3. Где логировать HTTP-вызов

Самое опасное место для диагностики — это main() и «класс, который печатает результат». Почему? Потому что там хочется логировать вообще всё подряд: и аргументы команды, и результат, и внутренние DTO, и JSON, и «мы сейчас пойдём в сеть». В итоге диагностика размазывается по проекту и начинает дублироваться. Сегодня вы добавили лог в ReadLaterApplication, завтра добавили похожий лог в CatalogClient, послезавтра — ещё один в transport-метод, и теперь у вас три одинаковые строки на один запрос. Поздравляю: вы построили «шумогенератор».

Диагностические сообщения про HTTP-вызов должны жить рядом с тем кодом, который этот HTTP-вызов делает. То есть там, где у вас создаётся HttpRequest, вызывается httpClient.send(...), получается HttpResponse, и дальше читается body. Это обычно ваш RealCatalogClient (или более низкий transport-класс, если вы уже его выделили). Точка входа (ReadLaterApplication) должна знать только «какая команда» и «какой пользовательский вывод». Она не должна превращаться в журнал событий внутренней кухни.

Полезно нарисовать простую схему потока, чтобы “прибить гвоздями” место диагностики:

flowchart TD
    A[ReadLaterApplication] --> B["CatalogPrinter / вывод"]
    B --> C[CatalogClient internal API]
    C --> D[RealCatalogClient transport]
    D --> E[HttpClient.send]
    E --> D
    D --> C
    C --> B
    B --> A

Идея простая: пользовательский текст живёт в A/B, а диагностические факты про HTTP — в D (там, где реальная сеть). Если вы будете следовать этой дисциплине, проект не расползётся в хаос даже до появления нормального логирования.

4. Замер времени запроса без магии

Замер времени — штука, которая кажется «опциональной», пока вы не столкнётесь с первым зависанием на 3 секунды. После этого вы начинаете мечтать, чтобы программа хотя бы сказала: «я пыталась 3000 мс, потом упала». Самое важное здесь — не усложнять. Нам не нужен профайлер и не нужен отдельный фреймворк, нам нужен честный замер длительности одной операции.

Для измерения длительности лучше использовать System.nanoTime(). Не потому что «наносекунды круто», а потому что это монотонный таймер. currentTimeMillis() может прыгнуть, если система синхронизирует время, а nanoTime() предназначен именно для интервалов. В переводе на человеческий: nanoTime() меньше врёт в стиле «время пошло назад».

Минимальный шаблон выглядит так:

long startedAtNs = System.nanoTime(); // старт замера (монотонный таймер)

// ... делаем HTTP-вызов ...

long durationMs = (System.nanoTime() - startedAtNs) / 1_000_000; // перевод наносекунд в миллисекунды
System.err.println("durationMs=" + durationMs); // durationMs=147

Если хочется сделать это чуть аккуратнее (чтобы не копировать формулу везде), можно добавить крошечный утилитный метод. Без архитектурной религии, просто чтобы читалось легче:

static long durationMs(long startedAtNs) {
    // startedAtNs берём из System.nanoTime() перед операцией, а тут считаем длительность
    return (System.nanoTime() - startedAtNs) / 1_000_000;
}

И тогда в коде будет выглядеть уже как «мы замеряем время», а не как «мы делим на миллион и надеемся, что не ошиблись нулём».

5. Happy-path: до запроса и после ответа

Теперь к практической части: что именно печатать и где. Для happy-path удобно иметь две строки. Первая — перед вызовом, чтобы видеть, куда мы собираемся идти. Вторая — после ответа, чтобы видеть статус и длительность. Да, это две строки, но они дают вам почти всё, что нужно для первичной диагностики.

Сделаем маленький класс-помощник для консольной диагностики. Он специально «тупой»: никаких уровней логирования, никаких конфигов, только формат сообщений и расчёт времени.

import java.net.URI;

public class ConsoleDiagnostics {

    public static long started(String operation, String mode, URI uri) {
        long startedAtNs = System.nanoTime(); // фиксируем время старта прямо перед HTTP-вызовом
        System.err.printf("DIAG %s mode=%s uri=%s%n", operation, mode, uri); // одна строка "куда идём"
        return startedAtNs; // возвращаем таймстамп, чтобы потом посчитать durationMs
    }

    public static void finished(String operation, String result, int status, long startedAtNs) {
        long durationMs = (System.nanoTime() - startedAtNs) / 1_000_000; // считаем длительность вызова
        System.err.printf("DIAG %s result=%s status=%d durationMs=%d%n",
                operation, result, status, durationMs); // одна строка "чем закончилось"
    }
}

Обратите внимание на две вещи. Во-первых, мы печатаем в System.err. Во-вторых, мы сразу фиксируем operation как строку, потому что потом это очень удобно искать. Даже если вы запускаете два запроса подряд, вы всегда понимаете, какой из них про search, а какой про details.

Теперь используем это в RealCatalogClient. Я покажу фрагмент «отправить GET и вернуть тело», потому что именно он является центром диагностики.

import java.io.IOException;
import java.net.URI;
import java.net.http.HttpClient;
import java.net.http.HttpRequest;
import java.net.http.HttpResponse;

public class RealCatalogClient {

    private final HttpClient httpClient;

    public RealCatalogClient(HttpClient httpClient) {
        this.httpClient = httpClient;
    }

    String getBody(String operation, URI uri) throws IOException, InterruptedException {
        long t0 = ConsoleDiagnostics.started(operation, "real", uri); // до вызова: режим + uri

        HttpRequest request = HttpRequest.newBuilder(uri)
                .GET() // явно указываем метод, чтобы не было "магии"
                .build();

        // здесь реально уходим в сеть и получаем ответ (или исключение)
        HttpResponse<String> response = httpClient.send(request, HttpResponse.BodyHandlers.ofString());

        // Не-2xx — это уже не happy-path: ответ пришёл, но обычный парсинг дальше не продолжаем.
        if (response.statusCode() / 100 != 2) {
            ConsoleDiagnostics.finished(operation, "http-error", response.statusCode(), t0);
            throw new IllegalStateException("Catalog responded with status " + response.statusCode());
        }

        ConsoleDiagnostics.finished(operation, "ok", response.statusCode(), t0); // после ответа: статус + длительность
        return response.body(); // payload отдаём дальше только для успешного ответа
    }
}

Смысл простой: даже если статус не 2xx, это всё равно ответ, а не «сетевая ошибка». Мы фиксируем это через result=http-error, чтобы не путать с реальным transport-сломом (когда ответа нет вообще). Но после такого ответа обычный happy-path уже не продолжается: мы не делаем вид, что получили нормальный JSON каталога для дальнейшего парсинга.

В консоли вы получите примерно такое (и это уже очень «backend-like»):

DIAG catalog.search mode=real uri=https://openlibrary.org/search.json?q=clean%20code
DIAG catalog.search result=ok status=200 durationMs=147

6. Диагностика negative-path: transport-error, http-error, mapping-error

Ошибки — это место, где диагностика либо становится вашей спасательной верёвкой, либо превращается в «ну, упало и упало». Важно различать три больших класса проблем. Первый — transport-ошибка: сеть, таймаут, DNS, соединение, прерывание потока. Второй — HTTP-ошибка: сервер ответил, но статус неуспешный. Третий — ошибка чтения данных: статус мог быть даже 200, но JSON оказался не тем, или DTO не совпало, и Jackson упал на десериализации.

Чтобы не путаться, удобно держать в голове такую таблицу:

Добавим в ConsoleDiagnostics метод для ошибок, чтобы формат сообщений не разъезжался по проекту:

import java.net.URI;

public class ConsoleDiagnostics {

    public static void failed(String operation, String result, URI uri, Exception e, long startedAtNs) {
        long durationMs = (System.nanoTime() - startedAtNs) / 1_000_000; // сколько прошло до падения
        System.err.printf("DIAG %s result=%s error=%s durationMs=%d uri=%s message=%s%n",
                operation,
                result, // transport-error / mapping-error / и т.п.
                e.getClass().getSimpleName(), // тип исключения: IOException, InterruptedException, ...
                durationMs,
                uri,
                e.getMessage()); // короткое сообщение исключения (без stacktrace)
    }
}

И теперь обработаем transport-ошибку там же, где делаем send(). Важно: InterruptedException нельзя «просто проглотить». Хорошая привычка — восстановить флаг прерывания.

import java.io.IOException;
import java.net.URI;

String getBody(String operation, URI uri) {
    long t0 = ConsoleDiagnostics.started(operation, "real", uri); // стартуем замер и печатаем "куда идём"

    try {
        HttpRequest request = HttpRequest.newBuilder(uri).GET().build();
        HttpResponse<String> response = httpClient.send(request, HttpResponse.BodyHandlers.ofString());

        if (response.statusCode() / 100 != 2) {
            // ответ есть, значит это не transport-error; но happy-path здесь уже заканчивается
            ConsoleDiagnostics.finished(operation, "http-error", response.statusCode(), t0);
            throw new IllegalStateException("Catalog responded with status " + response.statusCode());
        }

        ConsoleDiagnostics.finished(operation, "ok", response.statusCode(), t0);
        return response.body();
    } catch (IOException e) {
        // сеть/таймаут/DNS: ответа нет, значит transport-error
        ConsoleDiagnostics.failed(operation, "transport-error", uri, e, t0);
        throw new RuntimeException("Catalog call failed", e); // пробрасываем выше, чтобы не продолжать "как ни в чём не бывало"
    } catch (InterruptedException e) {
        // важный момент: восстанавливаем флаг прерывания потока
        Thread.currentThread().interrupt();
        ConsoleDiagnostics.failed(operation, "transport-error", uri, e, t0);
        throw new RuntimeException("Catalog call interrupted", e);
    }
}

Теперь добавим отдельную диагностику для mapping-error. Здесь важно не смешивать: HTTP-запрос мог быть успешен, и мы уже напечатали result=ok, но затем упали на JSON. В этом случае у вас будет две строки: «HTTP ок» и «маппинг не ок». Это нормально, потому что это две разные стадии. Если хочется делать строго «одна строка про итог», можно объединить, но для учебного проекта проще видеть обе.

import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.ObjectMapper;

void parseSearchResponse(String operation, String uri, String body, ObjectMapper mapper) {
    try {
        mapper.readTree(body); // пример: "маппим" JSON (в вашем коде это может быть readValue в DTO)
    } catch (JsonProcessingException e) {
        // сеть тут ни при чём: ответ пришёл, но формат данных не совпал с ожиданиями
        System.err.printf("DIAG %s result=mapping-error uri=%s message=%s%n",
                operation, uri, e.getOriginalMessage());
        throw new RuntimeException("Cannot parse catalog JSON", e); // поднимаем ошибку наверх, чтобы команда явно упала
    }
}

Заметьте цепочку. После http-error мы не пытаемся парсить body как будто это успешный 200, а после mapping-error не печатаем частично собранный результат. Транспортный слой уже оставил техническую диагностику рядом с вызовом, поэтому верхний CLI-слой делает только одну вещь: коротко сообщает пользователю, что команда не выполнена, и завершает сценарий.

Обратите внимание: мы опять не печатаем весь body. Мы печатаем тип ошибки и короткое сообщение. Этого достаточно, чтобы понять: проблема не в сети, а в контракте данных.

7. Не печатаем весь JSON

Самая распространённая «диагностика новичка» выглядит так: «если что-то не работает — распечатаю весь JSON». Первые пять минут это кажется гениальным. Потом вы получаете ответ на 200 килобайт, консоль превращается в ад, вы не можете найти нужную строку, и внезапно понимаете, что сами себе устроили DDoS… только на собственный мозг.

Есть и второй аспект: даже если сейчас данные безобидные, в реальном мире payload часто содержит что-то лишнее (токены, персональные данные, внутренние идентификаторы). Хорошая привычка — по умолчанию не логировать payload. Payload — это кандидат на отдельный режим отладки, но не на основной поток диагностики.

Что делать вместо печати JSON целиком? Самый простой компромисс — печатать размер body и, при необходимости, очень короткий «фрагмент» (например, первые 120 символов), но только в ошибочных сценариях. Для учебного проекта можно сделать так:

static String preview(String body) {
    // превью нужно, чтобы не печатать 200KB в консоль, но всё же видеть "что-то похожее на JSON"
    if (body == null) return "null";
    return body.length() <= 120 ? body : body.substring(0, 120) + "...";
}

System.err.printf("DIAG catalog.search bodyLen=%d bodyPreview=%s%n",
        body.length(), preview(body)); // DIAG ... bodyLen=532 bodyPreview={"docs":[{"key":"OL1M"...}

И всё же я бы держал это как «план Б». В большинстве случаев достаточно: uri, status, durationMs, errorType, message. Этого хватает, чтобы найти проблему в 80% ситуаций, не превращая консоль в свалку.

8. Типичные ошибки при диагностике клиентских вызовов

Ошибка №1: «чем больше логов — тем лучше».
На практике это работает наоборот. Когда вы начинаете дублировать URI, body, статус и ещё раз всё то же самое в соседних местах, консоль превращается в шум. А шум — это тоже баг: вы перестаёте различать важное и начинаете игнорировать сообщения. Диагностика должна быть компактной и стабильной по формату, иначе она теряет ценность.

Ошибка №2: не указывать имя операции в сообщении.
status=200 выглядит нормально, пока у вас один запрос. Но как только появляются catalog.search, catalog.details и повторные вызовы, такие сообщения перестают что-либо объяснять. Без имени операции вы теряете контекст. Минимальный стандарт — всегда указывать, какая именно операция выполнялась.

Ошибка №3: не измерять длительность вызова.
Без durationMs вы не понимаете, что произошло: быстрый отказ сервера или долгий таймаут. Эти ситуации требуют разной диагностики и разных решений. Особенно в учебных проектах с внешними API это критично — нестабильность провайдера становится видимой только через время выполнения.

Ошибка №4: смешивать transport-ошибки и HTTP-ошибки.
Если send(...) выбросил исключение — это transport-проблема (сеть, DNS, таймаут). Если вернулся HttpResponse с кодом 404 или 500 — это корректный ответ сервера, просто неуспешный. Когда вы логируете и обрабатываете их одинаково, вы теряете смысл диагностики и начинаете “лечить” не те проблемы.

Ошибка №5: проглатывать исключения “чтобы не мешали”.
Иногда хочется просто поймать исключение, напечатать что-то и идти дальше. Но без чёткого сигнала наверх вы теряете контроль над потоком выполнения. Особенно это касается InterruptedException: если вы его поймали и не восстановили флаг через Thread.currentThread().interrupt(), вы ломаете контракт потоков. Даже в CLI-проекте лучше сразу вырабатывать правильную привычку.