Зачем нужен журнал?
Ведение журнала (logging) — крайне важно для любого веб-приложения независимо от используемой платформы и языка, включая Spring Boot, Node.js и .NET Core. Регистрация происходящих событий необходима для мониторинга работоспособности и контроля поведения приложения, она позволяет быстрее и эффективнее устранять неполадки. Из журнала разработчики получают ценную информацию о поведении работающего приложения. Это позволяет следить за структурой трафика, поведением пользователей и производительностью системы.
Более того, ведение журнала важно для контроля системной безопасности, поскольку позволяет учитывать все действия и помогает выявлять и устранять нарушения безопасности. По сути, работающий журнал — это глаза и уши веб-приложения, дающие представление о его текущих операциях и незаменимые для поддержания производительности, безопасности и надежности.
Общая схема
Чаще всего регистрация событий приложения включает инициализацию единого регистратора (обычно в файле или консоли), где объединяются журналы из различных частей приложения. Такой централизованный набор журналов упрощает мониторинг и анализ, поскольку обеспечивает единое представление о поведении и состоянии различных модулей и компонентов приложения. Но представьте, что журналы станут слишком большими — тогда просматривать их будет непросто. При этом одной из проблем (которую мы будем решать далее) является разделение между журналами регистрации ошибок и прочей информации.
Вначале рассмотрим общие принципы ведения журнала и постепенно будем совершенствовать в нем способ регистрации. Возможно, это будет и не окончательным решением, но определенно хорошей отправной точкой.
Стандартная реализация
Для ведения журнала в обычном приложение Spring по умолчанию используется logback.
Поэтому начнем с создания небольшого файла конфигурации под названием src/main/resources/logback.xml
.
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<property name="logging.file.name" value="info-log" />
<property name="logging.file.path" value="./"/>
<!-- console log appender -->
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<!-- Normal log appender -->
<appender name="NORMAL_FILE" class="ch.qos.logback.core.FileAppender">
<file>${logging.file.path}/${logging.file.name}</file>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<root level="TRACE">
<appender-ref ref="NORMAL_FILE"/>
<appender-ref ref="CONSOLE"/>
</root>
</configuration>
Теперь создадим небольшой класс контроллера в src/main/java/<package>/LoggerDemoController.java
.
package com.sparkdev.testlogging.controllers;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.http.MediaType;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.RestController;
import java.util.HashMap;
import java.util.Map;
@RestController
public class LoggerDemoController {
private static final Logger LOGGER = LoggerFactory.getLogger(LoggerDemoController.class);
@GetMapping(value = "/log", consumes = MediaType.ALL_VALUE)
public ResponseEntity<Object> loggerTest(@RequestParam("q") String q){
Map<String, String> response = new HashMap<>();
try {
LOGGER.info("started...");
response.put("message", "normal flow of the application");
if(q.equalsIgnoreCase("exception")){
throw new RuntimeException("Testing the exception logging mechanism");
}
LOGGER.info("before sending response");
LOGGER.trace("response: "+ response);
return ResponseEntity.ok(response);
}catch (Exception ex){
LOGGER.error("Exception: "+ex.getMessage());
return ResponseEntity.internalServerError().build();
}
}
}
Этот фрагмент кода определяет в приложении Spring Boot класс LoggerDemoController. Метка @RestController указывает на то, что это веб-контроллер. В этот класс входит частный статический финальный регистратор (logger), инициализируемый с помощью LoggerFactory.getLogger (как обычно принято для логирования в приложениях Java).
У контроллера есть конечная точка /log
, обрабатывающая запросы GET всех медиа-типов. Метод loggerTest
принимает параметр запроса q
и регистрирует различные сообщения в зависимости от потока исполнения. Вначале регистрируется запуск процесса и создается карта откликов с сообщением по умолчанию. Если параметр q
равен exception
, генерируется RuntimeException
для имитации сценария ошибки, который затем перехватывается и регистрируется как ошибка. В противном случае контроллер регистрирует намерение отправить ответ вместе с trace-level log для его содержимого. В зависимости от результата операции (successful
или exception
), возвращается либо ответ, либо внутренняя ошибка сервера.
Приведенный код иллюстрирует основные методы ведения журнала в приложении Spring Boot, демонстрируя возможности регистрации различных уровней информации (информация, трассировка, ошибки) и обработки exceptions.
Чтобы все записывалось в наш файл и консоль, в файле log configuration для корневого регистратора (root logger) обратите внимание на уровень журнала TRACE
. В действительности порядок приоритета уровней журналов следующий: Trace < Debug < Info < Warn < Error < Fatal
. Установив уровень журнала на INFO наблюдайте за изменениями непосредственно.
Усовершенствованная версия
Разработаем небольшой вспомогательный класс LoggerFactory, который расширит возможности регистрации и выбора методов ведения журнала.
src/main/java/<package>/LoggerFactory.java
:
package com.sparkdev.testlogging.utils;
import org.slf4j.Logger;
import java.util.HashMap;
import java.util.Map;
public class LoggerFactory {
private static final Map<String, Logger> LOGGER_MAP = new HashMap<>();
private LoggerFactory() {
LOGGER_MAP.put("info_log", org.slf4j.LoggerFactory.getLogger("info_log"));
LOGGER_MAP.put("error_log", org.slf4j.LoggerFactory.getLogger("error_log"));
}
public static LoggerFactory getLogger() {
return new LoggerFactory();
}
public void info(String message) {
LOGGER_MAP.get("info_log").info(message);
}
public void error(String message) {
LOGGER_MAP.get("error_log").error(message);
}
public void error(String message, Throwable exception) {
LOGGER_MAP.get("error_log").error(message, exception);
}
}
Конечно, возможности у этого служебного класса достаточно ограниченные, но его можно расширить. Сначала рассмотрим изменения в конфигурации журналирования.
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<property name="logging.file.name" value="info-log" />
<property name="logging.file.path" value="./"/>
<property name="logging.error.file.name" value="error-log" />
<property name="logging.error.file.path" value="./"/>
<!-- console log appender -->
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<!-- Normal log appender -->
<appender name="NORMAL_FILE" class="ch.qos.logback.core.FileAppender">
<file>${logging.file.path}/${logging.file.name}</file>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<!-- Error log appender -->
<appender name="ERROR_FILE" class="ch.qos.logback.core.FileAppender">
<file>${logging.error.file.path}/${logging.error.file.name}</file>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<!-- Logger definitions for info -->
<logger name="info_log" level="info">
<appender-ref ref="NORMAL_FILE"/>
</logger>
<!-- Logger definitions for error -->
<logger name="error_log" level="error">
<appender-ref ref="ERROR_FILE"/>
</logger>
</configuration>
Теперь изменим контроллер для доступа к утилите LoggerFactory
вместо пакета slf4j
.
package com.sparkdev.testlogging.controllers;
import com.sparkdev.testlogging.utils.LoggerFactory;
import org.springframework.http.MediaType;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.RestController;
import java.util.HashMap;
import java.util.Map;
@RestController
public class LoggerDemoController {
private static final LoggerFactory LOGGER = LoggerFactory.getLogger();
@GetMapping(value = "/log", consumes = MediaType.ALL_VALUE)
public ResponseEntity<Object> loggerTest(@RequestParam("q") String q){
Map<String, String> response = new HashMap<>();
try {
LOGGER.info("started...");
response.put("message", "normal flow of the application");
if(q.equalsIgnoreCase("exception")){
throw new RuntimeException("Testing the exception logging mechanism");
}
LOGGER.info("before sending response");
return ResponseEntity.ok(response);
}catch (Exception ex){
LOGGER.error("Exception: "+ex.getMessage());
return ResponseEntity.internalServerError().build();
}
}
}
В этой реализации получаем 2 файла, а именно Info_log
и error_log
. Интуитивно понятно, что все ошибки регистрируются в error_log
, а все информационные журналы записываются в info_log
. Весь объем работы выполняется служебным классом.
Финальная версия
Создание вспомогательных (утилитных) классов сопряжено с целым рядом возможных ошибок. Их исправление может оказаться трудоемким процессом. Поэтому попытаемся настроить конфигурацию так, чтобы описанные выше задачи выполняли такие стандартные библиотеки, как slf4j и log4j2.
<?xml version="1.0" encoding="UTF-8"?>
<configuration status="WARN">
<property name="logging.error.file.name" value="error-log" />
<property name="logging.error.file.path" value="./"/>
<property name="logging.file.name" value="info-log" />
<property name="logging.file.path" value="./"/>
<!-- Normal log appender -->
<appender name="INFO_FILE" class="ch.qos.logback.core.FileAppender">
<file>${logging.file.path}/${logging.file.name}</file>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>INFO, DEBUG, TRACE</level>
</filter>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR, WARN</level>
<onMatch>DENY</onMatch>
<onMisMatch>NEUTRAL</onMisMatch>
</filter>
</appender>
<!-- Error log appender -->
<appender name="ERROR_FILE" class="ch.qos.logback.core.FileAppender">
<file>${logging.error.file.path}/${logging.error.file.name}</file>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>ERROR, WARN</level>
</filter>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>INFO, DEBUG, WARn</level>
<onMatch>DENY</onMatch>
<onMisMatch>NEUTRAL</onMisMatch>
</filter>
</appender>
<root level="INFO">
<appender-ref ref="INFO_FILE"/>
<appender-ref ref="ERROR_FILE"/>
</root>
</configuration>
Приведенная выше конфигурация позволяет исключить утилиту LoggerFactory, используя стандартный класс LoggerFactory из библиотеки slf4j. Контроллер выглядит так:
package com.sparkdev.testlogging.controllers;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.http.MediaType;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.RestController;
import java.util.HashMap;
import java.util.Map;
@RestController
public class LoggerDemoController {
private static final Logger LOGGER = LoggerFactory.getLogger(LoggerDemoController.class);
@GetMapping(value = "/log", consumes = MediaType.ALL_VALUE)
public ResponseEntity<Object> loggerTest(@RequestParam("q") String q){
Map<String, String> response = new HashMap<>();
try {
LOGGER.info("started...");
response.put("message", "normal flow of the application");
if(q.equalsIgnoreCase("exception")){
throw new RuntimeException("Testing the exception logging mechanism");
}
LOGGER.info("before sending response");
return ResponseEntity.ok(response);
}catch (Exception ex){
LOGGER.error("Exception: "+ex.getMessage());
return ResponseEntity.internalServerError().build();
}
}
}
В итоге мы получаем ту же самую функциональность, когда в одном файле журнала регистрируются инфо-сообщения, отладка и трассировка, а ошибки и предупреждения будут в другом файле журнала. Разработчики смогут раздельно трассировать ошибки и обычные файлы.
Заключение
Значительно более удобное и понятное ведение журнала в приложении Spring Boot обеспечивает настройка с раздельными уровнями и файлами. Гибкая мощная система ведения журналов Logback позволяет эффективно разделять в отдельные файлы журналы уровней INFO
и ERROR
. Такой подход упрощает анализ журналов и устранение неполадок, поскольку позволяет быстро получить доступ к журналам определенного типа, которые нужны для повседневного мониторинга или исследования ошибок.
Простота и эффективность этой конфигурации делают ее незаменимой для любого надежного приложения Spring Boot. Ясное и структурированное ведение журнала — это не просто хороший стиль программирования, а еще и упрощенные отладка и обслуживание приложений в рабочей среде.
Читайте также:
- Spring Boot, Kafka и WebSocket для отправки сообщений в реальном времени
- Упрощаем интеграцию Kafka со Spring Boot
- Ключевые вопросы для собеседования по Spring Boot в 2023 году. Часть 1
Читайте нас в Telegram, VK и Дзен
Перевод статьи M K Pavan Kumar: Effective Logging Practices for Spring Boot Applications