Раздел 9. Исключения, логирование, отладка

Глава 2. Логирование (Logging)

Уровни логирования: TRACE, DEBUG, INFO, WARN, ERROR. Когда что использовать. Иерархия и фильтрация

Логирование без уровней — это поток неразличимых сообщений, где критическая ошибка теряется среди рутинных уведомлений о старте компонента. Уровни логирования — это система классификации сообщений по степени серьезности и детализации, которая позволяет разделить диагностический вывод на категории и фильтровать их в зависимости от окружения и задачи.

SLF4J определяет пять стандартных уровней, упорядоченных по возрастанию серьезности: TRACE, DEBUG, INFO, WARN, ERROR. Каждый уровень включает в себя и все последующие. Если логгер настроен на уровень INFO, он пропускает сообщения INFO, WARN и ERROR, но подавляет TRACE и DEBUG. Это свойство называется иерархией уровней и является фундаментальным механизмом управления объемом логов.


Иерархия уровней SLF4J

Иерархия строится от наименее серьезного к наиболее серьезному. TRACE находится на дне пирамиды — это максимальная детализация, используемая исключительно для отладки сложных алгоритмов. DEBUG следует выше — диагностическая информация, полезная при разработке и расследовании проблем. INFO — стандартный уровень для рутинных событий приложения. WARN — сигнал о нештатной, но не критичной ситуации. ERROR — фиксация сбоев, нарушающих функциональность.

Logback расширяет эту шкалу двумя техническими уровнями: ALL и OFF. ALL пропускает все сообщения независимо от уровня, OFF подавляет все сообщения полностью. Эти уровни не используются в коде приложения, а применяются в конфигурации для полного включения или отключения логирования отдельных компонентов.


TRACE — трассировка выполнения

TRACE — самый низкий и самый детальный уровень. Он предназначен для трассировки потока выполнения на уровне отдельных шагов алгоритма, входа и выхода из методов, итераций циклов и ветвлений условий. SLF4J исторически не рекомендовал использование TRACE, добавив его только под давлением сообщества, поскольку существуют альтернативы или потому что сообщения TRACE часто избыточны. Тем не менее, уровень остается полезным для локальной отладки сложных рекурсивных или конечно-автоматных алгоритмов.

TRACE никогда не включается в production. Объем данных, генерируемый на этом уровне, на порядки превышает возможности дисковой подсистемы и систем агрегации. Включение TRACE в высоконагруженном сервисе приводит к деградации производительности из-за частых системных вызовов записи и переполнению буферов асинхронных appenders.

public void quickSort(int[] array, int left, int right) {
    logger.trace("Entering quickSort(left={}, right={})", left, right);
    
    if (left < right) {
        int pivot = partition(array, left, right);
        logger.trace("Pivot index={}, array state={}", pivot, Arrays.toString(array));
        
        quickSort(array, left, pivot - 1);
        quickSort(array, pivot + 1, right);
    }
    
    logger.trace("Exiting quickSort(left={}, right={})", left, right);
}

В этом примере TRACE фиксирует каждый рекурсивный вызов и состояние массива. При отладке алгоритма сортировки это позволяет восстановить полную историю преобразований. В production эти строки бесполезны и подавляются конфигурацией.


#Java #для_новичков #beginner #logging #Log4j2 #Logback #SLF4J #INFO #DEBUG #WARN #ERROR #TRACE

DEBUG — диагностика

DEBUG предназначен для информации, которая может потребоваться при диагностике проблем или при работе приложения в тестовом окружении. Это уровень для входных и выходных параметров методов, промежуточных вычислений, результатов запросов к внешним системам, решений бизнес-правил. DEBUG должен быть достаточно детальным для понимания потока выполнения, но не настолько, чтобы превратить лог в бессмысленный шум.

Ключевое различие между TRACE и DEBUG: DEBUG-логирование должно быть пригодным для включения в production на ограниченное время при расследовании инцидента. TRACE-логирование настолько детально, что его включение в production технически невозможно без деградации системы. DEBUG — это баланс между информативностью и производительностью.

public User authenticate(String username, String passwordHash) {
    logger.debug("Authentication attempt for user={}", username);
    
    User user = userRepository.findByUsername(username);
    logger.debug("User lookup result: found={}, status={}", 
        user != null, user != null ? user.getStatus() : "N/A");
    
    if (user == null || !user.getPasswordHash().equals(passwordHash)) {
        logger.debug("Authentication failed for user={}: invalid credentials", username);
        return null;
    }
    
    if (user.getStatus() == UserStatus.LOCKED) {
        logger.debug("Authentication failed for user={}: account locked", username);
        return null;
    }
    
    logger.debug("Authentication successful for user={}, roles={}", 
        username, user.getRoles());
    return user;
}

Этот метод логирует ключевые точки принятия решений без избыточной детализации. При расследовании проблемы аутентификации разработчик видит, на каком этапе произошел отказ: пользователь не найден, неверный пароль или заблокированный аккаунт.


INFO — рутинные события

INFO — стандартный уровень для production. Он фиксирует значимые события жизненного цикла приложения: запуск и остановка сервиса, успешное завершение пакетной операции, вход и выход пользователя, изменение состояния сущности. INFO-сообщения формируют операционную хронологию системы — просмотр логов уровня INFO и выше дает обзор основных событий без погружения в детали.

INFO не предназначен для ежесекундных событий. Если метод вызывается тысячи раз в минуту, его логирование на уровне INFO создаст неуправляемый поток данных. INFO должен использоваться для событий, которые происходят относительно редко и представляют интерес для операционной команды.

@Service
public class OrderProcessingService {
    
    @EventListener
    public void onApplicationReady(ApplicationReadyEvent event) {
        logger.info("Order processing service started, version={}, profile={}",
            buildProperties.getVersion(), 
            Arrays.toString(environment.getActiveProfiles()));
    }
    
    public Order processOrder(OrderRequest request) {
        logger.info("Processing orderId={}, customerId={}, amount={}", 
            request.getOrderId(), request.getCustomerId(), request.getAmount());
        
        Order order = executeBusinessLogic(request);
        
        logger.info("Order {} processed successfully, status={}, durationMs={}", 
            order.getId(), order.getStatus(), order.getProcessingDuration());
        return order;
    }
}

В этом примере INFO фиксирует старт сервиса и успешное завершение бизнес-операции. Оператор, просматривая логи, видит, что заказ обработан, но не видит деталей валидации каждого поля — это остается на уровне DEBUG.

#Java #для_новичков #beginner #logging #Log4j2 #Logback #SLF4J #INFO #DEBUG #WARN #ERROR #TRACE

WARN — предупреждения

WARN сигнализирует о нештатной ситуации, которая не нарушает основную функциональность, но требует внимания. Это неожиданное поведение, отклонение от нормы, ситуация, которая может указывать на надвигающуюся проблему. WARN не означает ошибку — приложение продолжает работу, но что-то пошло не так.

Классические сценарии для WARN: использование устаревшего API, получение неожиданного формата данных от внешней системы, превышение порога времени выполнения операции, отказ вторичного сервиса при наличии fallback, повторная попытка операции после временного сбоя.

public void sendNotification(User user, Notification notification) {
    try {
        notificationGateway.send(user.getEmail(), notification);
        logger.info("Notification sent to user={}", user.getId());
    } catch (GatewayTimeoutException e) {
        logger.warn("Notification gateway timeout for user={}, will retry asynchronously", 
            user.getId());
        enqueueForRetry(user, notification);
    }
}

Здесь таймаут шлюза уведомлений — это не ошибка, потому что операция будет повторена асинхронно. Однако это нештатная ситуация, которую операционная команда должна видеть для мониторинга здоровья внешней зависимости.


ERROR — ошибки

ERROR фиксирует сбои, которые нарушают функциональность приложения или отдельной операции. Это исключения, которые не были обработаны на нижних уровнях, отказы внешних систем, нарушение бизнес-правил без возможности восстановления. ERROR требует вмешательства — ручного или автоматизированного.

Важное правило: не каждое исключение должно логироваться на уровне ERROR. Если метод обрабатывает исключение и предпринимает корректирующие действия (retry, fallback, пропуск элемента), уровень должен быть WARN. ERROR используется, когда операция завершилась неудачно и нет механизма восстановления, или когда исключение пробрасывается на верхний уровень для аварийной обработки.

public void chargePayment(Payment payment) {
    try {
        paymentGateway.charge(payment);
        logger.info("Payment {} charged successfully", payment.getId());
    } catch (PaymentGatewayException e) {
        if (e.isRetryable()) {
            logger.warn("Payment {} failed with retryable error, scheduling retry", 
                payment.getId());
            scheduleRetry(payment);
        } else {
            logger.error("Payment {} failed with non-retryable error: {}", 
                payment.getId(), e.getMessage(), e);
            markAsFailed(payment);
        }
    }
}

В этом примере retryable-ошибка логируется как WARN, потому что система восстанавливается автоматически. Non-retryable ошибка — ERROR, потому что платеж окончательно не выполнен и требует ручного разбора.


#Java #для_новичков #beginner #logging #Log4j2 #Logback #SLF4J #INFO #DEBUG #WARN #ERROR #TRACE

Фильтрация и наследование уровней

Логгеры в SLF4J и Logback организованы в иерархическую структуру на основе их имен. Логгер com.example.service.OrderService наследует уровень от com.example.service, который наследует от com.example, и так до корневого логгера. Это свойство называется наследованием уровней.
Когда логгер не имеет явно назначенного уровня, он наследует уровень ближайшего предка, у которого уровень определен. Корневой логгер всегда имеет уровень и служит последней инстанцией. Это позволяет управлять детализацией на уровне пакета или класса без перекомпиляции.

// Псевдокод конфигурации Logback
Logger root = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
root.setLevel(Level.INFO);

Logger servicePackage = LoggerFactory.getLogger("com.example.service");
servicePackage.setLevel(Level.DEBUG);

Logger orderService = LoggerFactory.getLogger("com.example.service.OrderService");
// orderService не имеет явного уровня, наследует DEBUG от com.example.service

Свойство additivity определяет, будет ли сообщение, обработанное логгером, передаваться родительским логгерам. По умолчанию additivity равно true, что означает, что сообщение проходит через всю цепочку appenders от конкретного логгера до корневого.

Если additivity установлено в false, сообщение обрабатывается только appenders данного логгера и не поднимается выше.

<!-- Logback: отключение additivity для изоляции вывода -->
<logger name="com.example.audit" level="INFO" additivity="false">
    <appender-ref ref="AUDIT_FILE"/>
</logger>

В этом примере логгер com.example.audit направляет сообщения только в файл аудита, не дублируя их в корневой appender. Это критично для разделения потоков: бизнес-аудит не должен попадать в общий лог ошибок.
Практические рекомендации по выбору уровня

Выбор уровня — это не субъективное предпочтение, а архитектурное решение, влияющее на наблюдаемость системы.

Несколько правил, выработанных практикой:
Правило единственного уровня для исключения. Одно и то же событие не должно логироваться на разных уровнях в разных местах. Если метод перехватил исключение и залогировал его как ERROR, вызывающий код не должен логировать его повторно. Дублирование создает шум и затрудняет анализ.
Правило восстановимости. Если операция может быть восстановлена автоматически — WARN. Если восстановление невозможно — ERROR. Если это ожидаемое поведение — INFO или ниже.
Правило частоты. События, происходящие чаще нескольких раз в минуту на экземпляр, не должны логироваться на INFO. Используйте DEBUG или агрегируйте метриками.
Правило контекста. Сообщение должно содержать достаточно контекста для понимания проблемы без чтения кода. Вместо logger.error("Failed") используйте logger.error("Payment processing failed for orderId={}, gateway={}", orderId, gatewayId).
Правило guard-методов. Для дорогостоящих DEBUG и TRACE сообщений используйте logger.isDebugEnabled() или параметризованные сообщения SLF4J для исключения накладных расходов при отключенном уровне.

// Правильно: ленивое вычисление через параметризацию
logger.debug("Processing batch of {} items, estimated memory={}MB", 
    batchSize, estimatedMemory);

// Избыточно: guard-метод не нужен для простых параметров
if (logger.isDebugEnabled()) {
    logger.debug("Simple message");
}

// Оправдано: guard для дорогостоящих операций
if (logger.isDebugEnabled()) {
    logger.debug("Complex state: {}", serializeFullObjectGraph(state));
}

Согласованность уровней в распределенных системах

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


#Java #для_новичков #beginner #logging #Log4j2 #Logback #SLF4J #INFO #DEBUG #WARN #ERROR #TRACE