Вопрос 18 · Раздел 7

Как правильно логировать исключения?

Используйте логгер вместо printStackTrace():

Версии по языкам: English Russian Ukrainian

Junior Level

Базовое правило

Используйте логгер вместо printStackTrace():

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class OrderService {
    // Logger — static final, один на класс
    private static final Logger log = LoggerFactory.getLogger(OrderService.class);

    public void processOrder(Long orderId) {
        try {
            // business logic
        } catch (Exception e) {
            // Исключение — последним аргументом, есть контекст
            log.error("Failed to process order id={}", orderId, e);
        }
    }
}

Уровни логирования

  • log.error() — критические ошибки, требующие внимания
  • log.warn() — предупреждения, система работает но есть риск
  • log.info() — важные события (запуск, завершение)
  • log.debug() — детальная отладка

С параметрами

log.error("User id={} not found", userId, exception);
// exception НЕ попадет в {}, он пойдет в стек-трейс

Как работает SLF4J: SLF4J заменяет {} на значения аргументов слева направо. Но есть special case: если последний аргументThrowable, SLF4J не подставляет его в {}, а извлекает полный стек-трейс и добавляет его к сообщению.

// {} заменяется на userId, exception — последним аргументом → стек будет в логе
log.error("User id={} not found", userId, exception);

// {} заменяется на e.getMessage(), exception НЕ последним → стек НЕ попадёт в лог!
log.error("Error: {}", exception, userId);

// Нет {}, но exception последним → стек всё равно будет
log.error("Critical failure", exception);

Частая ошибка: log.error("Error: {}", e) — здесь e подставляется в {} как строка (e.toString()), но стек-трейс НЕ выводится. Всегда передавайте исключение последним аргументом, отдельно от {}.

Чего не делать

// ПЛОХО — нет контекста, невозможно понять где ошибка
log.error(e.getMessage());

// ПЛОХО — e как параметр {}, не как исключение (стек не попадёт в лог)
log.error("Error: {}", e);

// ПЛОХО — логирование и printStackTrace дублируют вывод
log.error("Error", e);
e.printStackTrace();

// ХОРОШО — исключение последним аргументом, есть контекст
log.error("Failed to process user id={}", userId, e);

Когда НЕ использовать логирование исключений

  1. Ожидаемые бизнес-сценарииUserNotFoundException при логине: это не ошибка системы, а нормальный сценарий. Используйте log.warn() или log.info() вместо log.error(). Если каждый неудачный логин пишет ERROR — ваши алерты обесценятся (alert fatigue)
  2. Retry-механизмы — не логируйте каждую попытку retry на уровне ERROR, используйте log.debug(). Иначе 5 попыток retry = 5 ERROR-логов, хотя система ещё борется
  3. Batch-обработка — при 1000 элементах с 500 ошибками используйте log sampling (не более 10 одинаковых стеков в минуту)
  4. Health check endpoint — ошибки health check логируйте на DEBUG, не засоряйте ERROR-логи
  5. Circuit breaker open — когда CB открыт, логируйте один раз при открытии, не каждую отклонённую просьбу
  6. Дублированное логирование — если исключение будет залогировано на верхнем уровне (GlobalExceptionHandler), не логируйте его ещё раз на каждом слое. Одно исключение — один ERROR-лог

Caveat: PII (Personally Identifiable Information) в логах

Никогда не логируйте чувствительные данные вместе с исключениями. Это включает:

  • Пароли, токены, CVV коды
  • Email, телефон, паспортные данные (GDPR!)
  • IP-адреса (в некоторых юрисдикциях)
// ПЛОХО — пароль в логе
log.error("Auth failed for user={} with password={}", username, password);

// ХОРОШО — только контекст без чувствительных данных
log.error("Auth failed for user={}", username);

Даже если логгер поддерживает маскировку, лучше вообще не передавать такие данные в логгер. Настройте лог-фреймворк на редракт (scrubbing) на уровне appender’а, а не в каждом вызове отдельно.


Middle Level

SLF4J магия последнего аргумента

SLF4J ищет последний аргумент метода. Если это Throwable, он обрабатывается особо — извлекается стек-трейс, даже если в строке нет {}:

log.error("Critical failure", exception); // Стек будет в логе

MDC (Mapped Diagnostic Context)

В распределённых системах стек-трейс бесполезен без контекста запроса:

MDC.put("traceId", traceId);
MDC.put("userId", userId);
try {
    orderService.process(orderId);
    // В логе будет traceId и userId
} catch (Exception e) {
    log.error("Failed to process order id={}", orderId, e);
} finally {
    MDC.clear(); // Обязательно — иначе traceId утечёт в следующий запрос
}

JSON Layout

В ELK/Splunk логи должны быть JSON:

{
  "timestamp": "2024-01-15T10:30:00Z",
  "level": "ERROR",
  "message": "Failed to process order",
  "exception_class": "java.sql.SQLException",
  "stack_trace": "...",
  "traceId": "abc-123"
}

Преимущества:

  • Индексирование по exception_class
  • Поиск по stack_trace
  • Нет проблем с многострочными логами

Cause Analysis

Убедитесь, что логгер выводит все уровни cause. Корень зла может быть на 5-м уровне вложенности.


Senior Level

Log Sampling

При огромной нагрузке и массовых ошибках можно “утонуть” в логах (Log Flooding). Продвинутые логгеры настраивают лимиты:

<!-- Logback — не более 10 одинаковых стеков в минуту -->
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <filter class="ch.qos.logback.classic.filter.DuplicateMessageFilter">
        <AllowedRepetitions>10</AllowedRepetitions>
    </filter>
</appender>

Async Appenders

Всегда используйте асинхронное логирование — отделяет запись на диск/сеть от бизнес-потока:

<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <appender-ref ref="FILE" />
    <includeCallerData>false</includeCallerData> <!-- для ускорения -->
</appender>

Риск: потеря последних логов при падении JVM.

Log Scrubbing (PII)

Никогда не логируйте чувствительные данные (пароли, CVV, токены). Современные логгеры поддерживают маскировку:

// Логгер автоматически маскирует
log.error("Auth failed for user with password={}", password);
// В логе: password=****

ShortenedThrowableConverter

Не печатайте 200 строк стека Hibernate. Обычно первых 20 кадров достаточно:

<conversionRule conversionWord="ex" 
    converterClass="com.example.ShortenedThrowableConverter" />

Generic Catch-all

Логирование catch (Exception e) на самом верхнем уровне обязательно, но должно сопровождаться алертингом (Prometheus/Grafana):

meterRegistry.counter("errors.unhandled").increment();
alertService.send("Unhandled exception: " + e.getMessage());

Диагностика

  • Logback Configuration — настройте <shortenedThrowableConverter>
  • Cause Analysis — логгер должен выводить все уровни cause
  • Structured Logging — JSON формат для ELK/Splunk
  • Metric-driven — каждое исключение через Micrometer в Prometheus

🎯 Шпаргалка для интервью

Обязательно знать:

  • Исключение — всегда последним аргументом в log.error("msg {}", param, e); SLF4J извлекает стек-трейс из последнего аргумента
  • НЕ используйте log.error("Error: {}", e) — здесь e подставляется в {} как строка, стек НЕ выводится
  • Используйте MDC (traceId, userId) для контекста в распределённых системах; обязательно MDC.clear() в finally
  • Для highload: async appender, log sampling (не более 10 одинаковых стеков/мин), shortenedThrowableConverter
  • Ожидаемые бизнес-сценарии логируйте на warn/info, не на error — иначе алерты обесценятся (alert fatigue)
  • Никогда не логируйте PII: пароли, токены, CVV, email (GDPR!), IP-адреса

Частые уточняющие вопросы:

  • Как SLF4J обрабатывает исключение? — Если последний аргумент — Throwable, SLF4J не подставляет его в {}, а извлекает полный стек-трейс
  • Почему не дублировать логирование? — Если GlobalExceptionHandler уже логирует, не логируйте на каждом слое — одно исключение = один ERROR-лог
  • Что такое Log Sampling? — Ограничение количества одинаковых сообщений (например, 10/мин) чтобы не «утонуть» в логах при массовых ошибках
  • Когда НЕ логировать исключение? — Ожидаемые бизнес-сценарии (UserNotFoundException при логине), retry-попытки, health check, circuit breaker open

Красные флаги (НЕ говорить):

  • “Логирую log.error(e.getMessage()) без контекста” — Невозможно понять где ошибка и что её вызвало
  • “Логирую пароль вместе с исключением” — Нарушение безопасности (GDPR, PCI DSS)
  • “Логирую и printStackTrace одновременно” — Дублирование, засоряет логи
  • “Каждый retry на уровне ERROR” — 5 попыток = 5 ERROR-логов, алерты становятся бесполезными

Связанные темы:

  • [[16. Что делает метод printStackTrace()]]
  • [[15. Что такое stack trace]]
  • [[13. Можно ли создавать кастомные исключения]]
  • [[19. Почему не стоит глотать исключения (catch empty)]]
  • [[18. Что такое оборачивание (wrapping) исключений]]