Java logging. Hello World

Пример целиком

Learn to use and configure logging to the console in a Spring boot application. Also, learn to configure and use console appenders available in logback and log4j2.

By default, Spring boot uses Logback as the logging provider.

#Log Levels
logging.level.org.springframework=DEBUG
logging.level.com.howtodoinjava=DEBUG
# Log Thresolds
logging.threshold.console=TRACE
logging.threshold.file=INFO
# Log to File
logging.file=${java.io.tmpdir}/app.log
# Log Patterns
logging.pattern.console= %d{yyyy-MM-dd HH:mm:ss} - %msg%n
logging.pattern.file= %d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%

Logback is intended as a successor to the log4j project and was designed by Ceki Gülcü. Logback is faster and has a smaller footprint than all existing logging systems. Logback performs about ten times faster than Log4j on specific critical execution paths.

The Logger class in logback-classic implements the SLF4J API natively, so we incur zero overhead when invoking an SLF4J logger with logback-classic as the underlying implementation. Using SLF4J API drastically reduces the work involved in switching logging frameworks.

Всем привет, JavaRush сообщество!

Сегодня поговорим о Java логировании:

1. Что это, зачем это. В каких случаях лучше использовать, в каких — нет.
2. Какие бывают реализации логирования в Java и что с этим разнообразием нам делать.

Уровни логирования. Обсудим, что такое appender и как его правильно настроить.

3. Узлы логирования и как правильно их настраивать, чтоб все работало так, как мы хотим.

Этот материал рассчитан на широкую аудиторию. Он будет понятен и тем, кто только знакомится с Java, и тем, кто уже работает, но разобрался только с logger.info(“log something”);

Поехали!

Profile Specific Log Configurations

Profile-specific properties always override the non-profile-specific ones. If several profiles are specified, a last-wins strategy applies. If I have two environments for my application i.e. prod and dev then I will create two profile-specific properties files.

logging.level.com.howtodoinjava=DEBUG
logging.pattern.console=%d{yyyy-MM-dd HH:mm:ss} - %msg%n

logging.level.com.howtodoinjava=ERROR
logging.pattern.console=%d{yyyy-MM-dd HH:mm:ss} - %msg%n

Задача

Допустим, нам захотелось логгировать каждый метод некого Java-класса по разному:

• Для каждого метода свой лог-файл,
• … свой формат лога,
• … свой минимальный уровень логгирования,
• формат лога расширяем собственными %переменными,
• возможность обновлять эту конфигурацию на лету.

Расширения Logback

Spring Boot содержит ряд расширений для Logback, которые могут упростить углубленное конфигурирование. Можно использовать эти расширения в конфигурационном файле logback-spring.xml.

Поскольку стандартный конфигурационный файл logback.xml загружается слишком рано, расширения в нем использовать нельзя. Необходимо либо использовать logback-spring.xml, либо определить свойство logging.config.

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

ERROR in ch.qos.logback.core.joran.spi.Interpreter@4:71 - no applicable action for [springProperty], current ElementPath is [[configuration][springProperty]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@4:71 - no applicable action for [springProfile], current ElementPath is [[configuration][springProfile]]

Связанная с конкретным профилем конфигурация

<springProfile name="staging"> <!-- конфигурация, которая будет активирована, если профиль "staging" активен -->
</springProfile>
<springProfile name="dev | staging"> <!-- конфигурация, которая будет активирована, если профиль "dev" или "staging" активен -->
</springProfile>
<springProfile name="!production"> <!-- конфигурация, которая будет активирована, если профиль "production" активен -->
</springProfile>

Свойства окружения

Тег <springProperty> позволяет открывать свойства из Environment в Spring для использования в Logback. Это может быть полезно, если необходимо получить доступ к значениям из файла application.properties в конфигурации Logback. Этот тег работает так же, как и стандартный тег <property> в Logback. Однако вместо задания прямого value вы задаете source свойства (из Environment). Если необходимо хранить свойство не в local области доступности, то можно использовать атрибут scope. Если необходимо запасное значение (на случай, если свойство не установлено в Environment), можно использовать атрибут defaultValue. В следующем примере показано, как открыть свойства для использования в Logback:

<springProperty scope="context" name="fluentHost" source="myapp.fluentd.host" defaultValue="localhost"/>
<appender name="FLUENT" class="ch.qos.logback.more.appenders.DataFluentAppender"> <remoteHost>${fluentHost}</remoteHost> ...
</appender>

Задавать source нужно в кебаб-регистре (например, my.property-name). Однако свойства можно добавлять в Environment посредством нестрогих правил.

Группы логов

Во многих случаях полезно иметь возможность группировать связанные диспетчеры логирования вместе, чтобы их можно было конфигурировать одновременно. Например, можно часто менять уровни ведения лога для всех диспетчеров логирования, связанных с Tomcat, но легко запомнить пакеты верхнего уровня не выйдет.

Чтобы помочь в этом, Spring Boot позволяет определять группы логирования в вашей Environment для Spring. Например, вот как вы можете определить «tomcat-группу», добавив ее в файл application.properties:

logging.group.tomcat=org.apache.catalina,org.apache.coyote,org.apache.tomcat

logging: group: tomcat: "org.apache.catalina,org.apache.coyote,org.apache.tomcat"

После определения можно изменять уровень для всех диспетчеров логирования в группе с помощью одной строки:

logging.level.tomcat=trace

logging: level: tomcat: "trace"

Spring Boot содержит следующие предопределенные группы логирования, которые можно использовать «из коробки»:

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

Что такое уровни логирования? Для того, чтоб как-то ранжировать логи, нужно было дать определенные обозначения и разграничения. Для этого ввели уровни логирования.

Уровень задается в приложении. Если запись относится к уровню ниже обозначенного, она не вносится в лог.

Например, у нас есть логи, с помощью которых дебажат приложение. В нормальной работе на продакшене (когда приложение используют по назначению), такие логи не нужны. Поэтому уровень логирования будет выше, чем для дебага.

Давайте рассмотрим уровни на примере log4j. Остальные решения, кроме JUL, используют такие же уровни. Вот они в порядке уменьшения:

• OFF: никакие логи не записываются, все будут проигнорированы;
• FATAL: ошибка, после которой приложение уже не сможет работать и будет остановлено, например, JVM out of memory error;
• ERROR: уровень ошибок, когда есть проблемы, которые нужно решить. Ошибка не останавливает работу приложения в целом. Остальные запросы могут работать корректно;
• WARN: обозначаются логи, которые содержат предостережение. Произошло неожиданное действие, несмотря на это система устояла и выполнила запрос;
• INFO: лог, который записывает важные действия в приложении. Это не ошибки, это не предостережение, это ожидаемые действия системы;
• DEBUG: логи, необходимые для отладки приложения. Для уверенности в том, что система делает именно то, что от нее ожидают, или описания действия системы: “method1 начал работу”;
• TRACE: менее приоритетные логи для отладки, с наименьшим уровнем логирования;
• ALL: уровень, при котором будут записаны все логи из системы.

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

Логирование

Spring Boot использует Commons Logging для всеохватывающего логирования (журналирования, logging) на внутреннем уровне, но оставляет открытой базовую реализацию лога. Конфигурации по умолчанию предусмотрены для Java Util Logging, Log4J2 и Logback. В каждом случае диспетчеры логирования предварительно сконфигурированы на использование консольного вывода с возможностью вывода в файл.

По умолчанию, если используются «Стартеры», для ведения лога используется Logback. Соответствующая маршрутизация Logback также предусмотрена для обеспечения корректной работы зависимых библиотек, использующих Java Util Logging, Commons Logging, Log4J или SLF4J.

Для Java доступно множество фреймворков логирования. Не волнуйтесь, если приведенный выше список вводит в ступор. Как правило, изменять зависимости логирования не нужно, и настройки Spring Boot по умолчанию работают просто отлично.

Если вы развертываете свое приложение в контейнере сервлетов или на сервере приложений, логирование, выполняемое с помощью API- интерфейса Java Util Logging, не маршрутизируется к логам приложения. Это предотвращает появление в логах приложения записей, выполняемых контейнером или другими приложениями, которые были развернуты в нем.

Custom Log Levels

In the application.properties file, we can define log levels of Spring Boot loggers, application loggers, Hibernate loggers, Thymeleaf loggers, and more. To set the logging level for any logger, add properties starting with logging.level.

The logging level can be one of one of TRACE, DEBUG, INFO, WARN, ERROR, FATAL, OFF. The root logger can be configured using logging.level.root.

If we are using Logback or Log4j2, we can configure different log levels for console logs and file logs using the configuration properties logging.threshold.console and logging.threshold.file.

logging.level.root=WARN
logging.level.org.springframework.web=ERROR
logging.level.com.howtodoinjava=DEBUG
logging.threshold.console=TRACE
logging.threshold.file=INFO

In the above configuration, I upgraded the log level for application classes to DEBUG (from default INFO).

Now observe the logs:

2017-03-02 23:57:14.966 DEBUG 4092 --- [nio-8080-exec-1] c.h.app.controller.IndexController : debug log statement printed
2017-03-02 23:57:14.967 INFO 4092 --- [nio-8080-exec-1] c.h.app.controller.IndexController : info log statement printed
2017-03-02 23:57:14.967 WARN 4092 --- [nio-8080-exec-1] c.h.app.controller.IndexController : warn log statement printed
2017-03-02 23:57:14.967 ERROR 4092 --- [nio-8080-exec-1] c.h.app.controller.IndexController : error log statement printed

Клиентский код

 class ThingService { log = LoggerFactory.getLogger(); getThing() { log.debug("getThing..."); // => one.log } listThings() { log.debug("listThings..."); // => another.log } }

Свой формат на каждый метод

Для этого держим кэш авто-создаваемых объектов типа Encoder:

 Map<String, String> patternByMethod = new HashMap<>(); // вызывается выше; упрощёно Encoder getOrCreateEncoderByMethod(LoggerContext lc, String method) { String pattern = patternByMethod.get(method); encoder = new PatternLayoutEncoder(); encoder.setContext(lc); encoder.setPattern(pattern); encoder.start(); return encoder; }

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

Для демонстрации будем использовать интерфейс slf4j, а реализацию — от log4j.

Создать логгер очень просто: нужно написать в классе с именем MainDemo, в котором будет логирование, следующее:

org.slf4j.Logger logger = org.slf4j.LoggerFactory.getLogger(MainDemo.class);

Это и создаст нам логгер.

Чтобы сделать запись в лог, можно использовать множество методов, которые показывают, с каким уровнем будут записи. Например:

logger.trace("Method 1 started with argument={}", argument);
logger.debug("Database updated with script = {}", script);
logger.info("Application has started on port = {}", port);
logger.warn("Log4j didn't find log4j.properties. Please, provide them");
logger.error("Connection refused to host = {}", host);

Хоть мы и передаем класс, по итогу записывается именно полное имя класса с пакетами. Это делается, чтобы потом можно было разделить логирование на узлы, и для каждого узла настроить уровень логирования и аппендер.

Например, имя класса: com.github.romankh3.logginglecture.MainDemo — в нем создался логгер. И вот таким образом его можно разделить на узлы логирования.

Главный узел — нулевой RootLogger. Это узел, который принимает все логи всего приложения. Остальные можно изобразить, как показано ниже:
Аппендеры настраивают свою работу именно на узлы логирования. Сейчас на примере log4j.properties будем смотреть, как их настроить.

Logback

Для реализации выбрана добротная библиотека логгирования «logback», предоставляющая интересные возможности для кастомизации:

ch.qos.logback:logback-classic:1.2.3

Настраивается как из XML-конфига, так и напрямую из Джавы, подходы можно комбинировать:

 public void configureLogback() throws JoranException { LoggerContext lc = LoggerFactory.getILoggerFactory(); lc.reset(); // reset prev config JoranConfigurator configurator = new JoranConfigurator(); configurator.setContext(lc); configurator.doConfigure("config.xml"); // any data source StatusPrinter.printInCaseOfErrorsOrWarnings(lc); // а теперь комбинация: Logger root = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME); root.setLevel(Level.INFO); // переопределение }

Вкратце о логгировании:

1. Программист дергает логгер,
2. Логгер дергает назначенные ему аппендеры,
3. Аппендер думает и вызывает энкодер,
4. Энкодер форматирует ровно одну строку лога,
5. Для этого он дёргает цепочку конвертеров, каждый из которых раскрывает свою %переменную,
6. Успех.

Для простоты была выбрана чистая джавиная конфигурация. Тут всё довольно очевидно если держать перед глазами XML-конфиг. Основная задача — создать свои собственные appender/encoder и зарегистрировать их — они будут вызываться логбэком из своих недр. Почти каждый создаваемый объект нужно не забыть запустить методом start(). Абстрактный пример:

 Logger rootLogger = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME); LoggerContext lc = rootLogger.getLoggerContext(); lc.reset(); // reset prev config var encoder = new PatternLayoutEncoder(); encoder.setContext(lc); encoder.setPattern("%-5level %message%n"); encoder.start(); var appender = new ConsoleAppender<ILoggingEvent>(); appender.setContext(lc); appender.setEncoder(encoder); appender.start(); rootLogger.setLevel(Level.DEBUG); rootLogger.addAppender(appender);

Custom Log Patterns

To change the logging patterns, use logging.pattern.console and logging.pattern.file properties.

# Logging pattern for the console
logging.pattern.console=%d{yyyy-MM-dd HH:mm:ss} - %msg%n
# Logging pattern for file
logging.pattern.file=%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n

After changing the console logging pattern in the application, log statements are printed as below:

2017-03-03 12:59:13 - This is a debug message
2017-03-03 12:59:13 - This is an info message
2017-03-03 12:59:13 - This is a warn message
2017-03-03 12:59:13 - This is an error message

Популярные ошибки в логировании

Нюансов много, но можно выделить несколько частых ошибок:

1. Избыток логирования. Не стоит логировать каждый шаг, который чисто теоретически может быть важным. Есть правило: логи могут нагружать работоспособность не более, чем на 10%. Иначе будут проблемы с производительностью.
2. Логирование всех данных в один файл. Это приведет к тому, что в определенный момент чтение/запись в него будет очень сложной, не говоря о том, что есть ограничения по размеру файлов в определенных системах.
3. Использование неверных уровней логирования. У каждого уровня логирования есть четкие границы, и их стоит соблюдать. Если граница расплывчатая, можно договориться какой из уровней использовать.

Кастомная конфигурация лога

Различные системы логирования можно активировать путем включения соответствующих библиотек в classpath и дополнительно специфически настроить путем передачи соответствующего конфигурационного файла в корне classpath или в местоположении, заданном следующим свойством Environment для Spring: logging.config.

Можно сделать так, чтобы Spring Boot в принудительном порядке использовать определенную систему логирования при помощи системного свойства org.springframework.boot.logging.LoggingSystem. Значение должно быть полным именем класса реализации LoggingSystem. Также можно полностью отключить конфигурацию логирования Spring Boot, используя значение none.

В зависимости от системы логирования загружаются следующие файлы:

Если это возможно, рекомендуем использовать варианты -spring для конфигурации логирования (например, logback-spring.xml, а не logback.xml). Если используются стандартные местоположения конфигурации, Spring не сможет полностью управлять инициализацией лога.

Существуют известные особенности с загрузкой классов в Java Util Logging, которые вызывают проблемы при запуске из «исполняемого jar-файла». Мы рекомендуем по возможности избегать этого при запуске из «исполняемого jar-файла».

Для упрощения настройки некоторые другие свойства переносятся из Environment для Spring в системные свойства, как описано в следующей таблице:

Если вы используете Logback, также передаются следующие свойства:

Все поддерживаемые системы логирования могут обращаться к системным свойствам при парсинге своих конфигурационных файлов. Смотрите примеры конфигураций по умолчанию в spring-boot.jar:

Если вам нужно использовать плейсхолдер в свойстве логирования, то следует придерживаться синтаксиса Spring Boot, а не синтаксиса базового фреймворка. В частности, если вы используете Logback, то следует использовать : в качестве разделителя между именем свойства и его значением по умолчанию, а не :-.

2019-08-30 12:30:04.031 user:someone INFO 22174 --- [ nio-8080-exec-0] demo.Controller
Handling authenticated request

Дополнительные материалы

1. JavaRush: Логирование. Размотать клубок стектрейса
2. JavaRush: Logger lecture
3. Хабр: Java logging. Hello world
4. Хабр: Java logging: история кошмара
5. Youtube: Головач курсы. Логирование. Часть 1, Часть 2, Часть 3, Часть 4
6. Log4j: appender
7. Log4j: layout

Пошаговая настройка Log4j. properties

Сейчас мы поэтапно все настроим и посмотрим, что можно сделать:

log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender

Эта строка говорит, что мы регистрируем аппендер CONSOLE, который использует реализацию org.apache.log4j.ConsoleAppender. Этот аппендер записывает данные в консоль.

Далее зарегистрируем еще один аппендер, который будет записывать в файл:

log4j.appender.FILE=org.apache.log4j.RollingFileAppender

Важно отметить, что аппендеры нужно будет еще настроить.

Когда у нас уже есть зарегистрированные аппендеры, мы можем определить, какой будет уровень логирования в узлах и какие аппендеры будут при этом использоваться.

log4j.rootLogger=DEBUG, CONSOLE, FILE

• log4j.rootLogger означает, что будем настраивать главный узел, в котором находятся все логи;
• после знака равно первое слово говорит о том, с каким уровнем и выше будут записываться логи (в нашем случае это DEBUG);
• далее после запятой указываются все аппендеры, которые будут использоваться.

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

log4j.logger.com.github.romankh3.logginglecture=TRACE, OWN, CONSOLE

где log4j.logger. используется для настройки определенного узла, в нашем случае это com.github.romankh3.logginglecture.

А теперь поговорим о настройке CONSOLE аппендера:

# CONSOLE appender customisation
log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
log4j.appender.CONSOLE.threshold=DEBUG
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
log4j.appender.CONSOLE.layout.ConversionPattern=[%-5p] : %c:%L : %m%n

Здесь мы видим, что можно задать уровень, с которого будет обрабатывать именно аппендер. Реальная ситуация: сообщение с уровнем info принял узел логирования и передал аппендеру, который к нему приписан, а вот уже аппендер, с уровнем warn и выше, лог этот принял, но ничего с ним не сделал.

Далее нужно определиться с тем, какой шаблон будет в сообщении. Я использую в примере PatternLayout, но там существует множество решений. В данной статье они не будут раскрыты.

Пример настройки FILE аппенедра:

# File appender customisation
log4j.appender.FILE=org.apache.log4j.RollingFileAppender
log4j.appender.FILE.File=./target/logging/logging.log
log4j.appender.FILE.MaxFileSize=1MB
log4j.appender.FILE.threshold=DEBUG
log4j.appender.FILE.MaxBackupIndex=2
log4j.appender.FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.FILE.layout.ConversionPattern=[ %-5p] - %c:%L - %m%n

Здесь можно настроить, в какой именно файл будут записываться логи, как видно из

log4j.appender.FILE.File=./target/logging/logging.log

Запись идет в файл logging.log.

Чтобы не было проблем с размером файла, можно настроить максимальный: в данном случае — 1МБ.

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

Чтоб посмотреть на реальный пример, где настроено логирование, можно перейти на открытый репозиторий на GitHub.

Что нужно логировать

Разумеется, логировать все подряд не стоит. Иногда это и не нужно, и даже опасно. Например, если залогировать чьи-то личные данные и это каким-то образом всплывет на поверхность, будут реальные проблемы, особенно на проектах, ориентированных на Запад.

Но есть и то, что логировать обязательно:

1. Начало/конец работы приложения. Нужно знать, что приложение действительно запустилось, как мы и ожидали, и завершилось так же ожидаемо.
2. Вопросы безопасности. Здесь хорошо бы логировать попытки подбора пароля, логирование входа важных юзеров и т.д.
3. Некоторые состояния приложения. Например, переход из одного состояния в другое в бизнес процессе.
4. Некоторая информация для дебага, с соответственным уровнем логирования.
5. Некоторые SQL скрипты. Есть реальные случаи, когда это нужно. Опять-таки, умелым образом регулируя уровни, можно добиться отличных результатов.
6. Выполняемые нити(Thread) могут быть логированы в случаях с проверкой корректной работы.

Высокоуровневая конфигурация ведения журнала

Spring Boot предлагает значительную поддержку для настройки ведения журнала в соответствии с нашими требованиями к ведению журнала.

На высоком уровне мы можем изменить параметры командной строки или добавить свойства application.properties(или application.yml), чтобы настроить некоторые функции ведения журнала.

Настройка уровня журнала с помощью параметра командной строки

Иногда нам необходимо просмотреть подробные журналы для устранения неполадок в поведении приложения. Для этого мы отправляем желаемый уровень журнала в качестве аргумента при запуске нашего приложения.

java -jar target/springLogger-0.0.1-SNAPSHOT.jar --trace

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

Настройка ведения журнала на уровне пакета

В большинстве случаев нас больше интересует вывод журнала написанного нами кода, а не вывод журнала из таких фреймворков, как Spring. Мы контролируем ведение журнала, указывая имена пакетов в переменной окружения log.level.<package-name>:

java \\ -jar target/springLogger-0.0.1-SNAPSHOT.jar \\ -Dlogging.level.org.springframework=ERROR \\ -Dlogging.level.io.pratik=TRACE

В качестве альтернативы мы можем указать наш пакет в application.properties:

logging.level.org.springframework=ERROR
logging.level.io.app=TRACE

Журналирование в файл

Мы можем записывать наши журналы в файл, установив только одно из свойств logging.file.nameили logging.file.pathв нашем application.properties. По умолчанию для вывода в файл установлен уровень журнала info.

# Output to a file named application.log.
logging.file.name=application.log

# Output to a file named spring.log in path /Users
logging.file.path=/Users

Если заданы оба свойства, только logging.file.nameвступает в силу.

Обратите внимание, что название этих свойств изменилось в Spring 2.2 и далее, но в официальной документации это еще не отражено. Наш пример работает с версией 2.3.2.RELEASE.

Помимо имени файла, мы можем переопределить шаблон ведения журнала по умолчанию с помощью свойства logging.pattern.file:

# Logging pattern for file
logging.pattern.file= %d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%

Другие свойства, связанные с файлом журнала:

Мы можем применить ту же настройку в отдельном файле конфигурации, как мы увидим в следующем разделе.

Отключение баннера

Spring баннер в верхней части файла журнала не добавляет никакой информации. Мы можем отключить баннер, установив для свойства значение off в application.properties:

spring.main.banner-mode=off 

Изменение цвета вывода журнала в консоли

Мы можем отображать вывод с цветовой кодировкой ANSI, установив spring.output.ansi.enabledсвойство. Возможные значения: ВСЕГДА, ОБНАРУЖЕНИЕ и НИКОГДА.

spring.output.ansi.enabled=ALWAYS

По умолчанию для свойства spring.output.ansi.enabledустановлено DETECTзначение. Цветной вывод действует только в том случае, если целевой терминал поддерживает коды ANSI.

Переключение реализации журналирования

Logback стартер является частью стартера Spring Boot по умолчанию. Мы можем заменить его на реализации log4j или java util, включив их стартеры и исключив стартер по умолчанию spring-boot-starter-loging в pom.xml:

<dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-web</artifactId> <exclusions> <exclusion> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-logging</artifactId> </exclusion> </exclusions>
</dependency>
<dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

Низкоуровневая конфигурация ведения журнала в logback-spring.xml

Мы можем изолировать конфигурацию журнала из приложения, указав конфигурацию logback.xmlили logback-spring.xmlв XML или заводной синтаксиса. Spring рекомендует использовать logback-spring.xmlили, logback-spring.groovyпотому что они более мощные.

Конфигурация по умолчанию состоит из appenderэлемента внутри корневого configurationтега. Шаблон указывается внутри encoderэлемента:

<configuration > <include resource="/org/springframework/boot/logging/logback/base.xml" /> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n </pattern> </encoder> </appender>
</configuration>

Ведение журнала с конфигурацией Logback

Если мы установим для debugсвойства в configurationтеге значение true, мы сможем увидеть значения конфигурации логбэка во время запуска приложения.

<configuration debug="true">

Запуск нашего приложения с этим параметром дает результат, содержащий значения конфигурации Logback, используемого в приложении:

...- About to instantiate appender of type [...ConsoleAppender]
...- About to instantiate appender of type [...RollingFileAppender]
..SizeAndTimeBasedRollingPolicy.. - setting totalSizeCap to 0 Bytes
..SizeAndTimeBasedRollingPolicy.. - ..limited to [10 MB] each.
..SizeAndTimeBasedRollingPolicy.. Will use gz compression
..SizeAndTimeBasedRollingPolicy..use the pattern /var/folders/
..RootLoggerAction - Setting level of ROOT logger to INFO

Отслеживание запросов через микросервисы

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

Мы можем сопоставить наши журналы и запросы трассировки между микросервисами, добавив информацию отслеживания в шаблон ведения журнала в logback-spring.xml. Пожалуйста, ознакомьтесь с трассировкой в ​​распределенных системах для более подробного объяснения распределенной трассировки.

Агрегирование журналов на сервере журналов

Журналы из разных микросервисов можно собирать в центральном месте. Для Spring Boot нам нужно выводить журналы в формате, совместимом с программным обеспечением агрегирования журналов. Давайте посмотрим на приложение, настроенное для Logstash:

 <appender name="LOGSTASH" class="net.logstash.logback.appender.LogstashTcpSocketAppender"> <destination>localhost:4560</destination> <encoder charset="UTF-8" class="net.logstash.logback.encoder.LogstashEncoder" /> </appender>

Здесь LogstashEncoderжурналы кодируются в формате JSON и отправляются на сервер журналов по адресу localhost:4560. Затем мы можем применить различные инструменты визуализации к журналам запросов.

Настройка ведения журнала для разных сред

У нас часто используются разные форматы журналов для локальной и производственной среды выполнения. Профили Spring — это элегантный способ реализовать различное ведение журнала для каждой среды. В этой статье вы можете сослаться на очень хороший пример использования ведения журнала для конкретной среды .

Default Logging in Spring Boot

Spring boot internally uses Apache’s common logging and uses Logback as the default logging provider. If we do not make any logging-specific configuration, we still see lots of logging output to the console which is good enough for POC (proof of concept) purposes.

We can find all default console logging configurations in these packaged files.

<conversionRule conversionWord="clr"
converterClass="org.springframework.boot.logging.logback.ColorConverter" />
<conversionRule conversionWord="wex"
converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter" />
<conversionRule conversionWord="wEx"
converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter" />
<property name="CONSOLE_LOG_PATTERN" value="${CONSOLE_LOG_PATTERN:-%clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}})
{faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(—){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39})
{cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>${CONSOLE_LOG_PATTERN}</pattern> </encoder>
</appender>
<root level="INFO"> <appender-ref ref="CONSOLE" />
</root>

Конфигурация журнала Spring Boot по умолчанию

Конфигурация ведения журнала по умолчанию в Spring Boot — это реализация Logback на уровне информации для записи вывода на консоль.

Давайте посмотрим на это поведение в действии, создав приложение Spring Boot. Мы создаем минимальное приложение только с веб-зависимостью, используя start.spring.io . Затем мы добавляем несколько операторов журнала в файл класса приложения:

@SpringBootApplication
public class SpringLoggerApplication { static final Logger log = LoggerFactory.getLogger(SpringLoggerApplication.class); public static void main(String[] args) { log.info("Before Starting application"); SpringApplication.run(SpringLoggerApplication.class, args); log.debug("Starting my application in debug with {} args", args.length); log.info("Starting my application with {} args.", args.length); } }

После компиляции с помощью Maven или Gradle и запуска полученного файла jar мы можем увидеть, как наши записи журнала печатаются в консоли:

13:21:45.673 [main] INFO io.pratik.springLogger.SpringLoggerApplication - Before Starting application . ____ _ __ _ _ /\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.3.2.RELEASE)
.
.
.
... : Started SpringLoggerApplication in 3.054 seconds (JVM running for 3.726)
... : Starting my application 0

Печатается первый информационный журнал, за ним следует семистрочный баннер Spring, а затем следующий информационный журнал. Записи отладки отключены.

Многопоточность

Если законфигурированный нами метод вызывает к жизни новые потоки, то на них, естественно, заданные правила логгирования распространяться не будут — в новом потоке thread local’ы сами собой не появятся. Так что, если хочется применить настройки метода к новому потоку, придётся скопировать туда MDC:

 Map<String, String> mdcOrig = MDC.getCopyOfContextMap(); ExecutorService es = Executors.newFixedThreadPool(1); es.submit(() -> threadWorker(mdcOrig)); void threadWorker(Map<String, String> parentMdc) { MDC.setContextMap(parentMdc); log.error("expected to appear in method2*.log"); }

Для чего нужно логирование

Давайте разберем реальные случаи, в которых логирование решало бы проблему.

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

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

Color-coded Logs

If your terminal supports ANSI, the color output will be used to aid readability. You can set spring.output.ansi.enabled value to either ALWAYS, NEVER or DETECT.

Color coding is configured using the %clr conversion word. In its simplest form, the converter will color the output according to the log level.

• FATAL and ERROR –
• WARN –
• INFO, DEBUG and TRACE –

Drop me your questions in the comments section.

Happy Learning !!

Формат логгера

Вывод лога по умолчанию в Spring Boot похож на следующий пример:

2022-10-20 12:40:11.311 INFO 16138 --- [ main] o.s.b.d.f.s.MyApplication : Starting MyApplication using Java 1.8.0_345 on myhost with PID 16138 (/opt/apps/myapp.jar started by myuser in /opt/apps/)
2022-10-20 12:40:11.330 INFO 16138 --- [ main] o.s.b.d.f.s.MyApplication : No active profile set, falling back to 1 default profile: "default"
2022-10-20 12:40:13.056 INFO 16138 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2022-10-20 12:40:13.070 INFO 16138 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2022-10-20 12:40:13.070 INFO 16138 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.68]
2022-10-20 12:40:13.178 INFO 16138 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2022-10-20 12:40:13.178 INFO 16138 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1762 ms
2022-10-20 12:40:13.840 INFO 16138 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2022-10-20 12:40:13.850 INFO 16138 --- [ main] o.s.b.d.f.s.MyApplication : Started MyApplication in 4.062 seconds (JVM running for 5.452)

Выводятся следующие элементы:

• Дата и время: точность до миллисекунды и легкая сортировка.

• Уровень ведения лога: ERROR, WARN, INFO, DEBUG или TRACE.

• Разделитель --- для разделения начала фактических сообщений лога.

• Название потока: заключено в квадратные скобки (может быть усечено для вывода в консоль).

• Имя диспетчера логирования: обычно это имя исходного класса (часто сокращенное).

Logback не имеет уровня FATAL. Он отображается на ERROR.

FAQs

5.1. How to print Jar files names in logs

Once configured, logback can include packaging data (name and version of the jar file) for each line of the stack trace lines it outputs. It can help debug identifying ClassCastException issues due to multiple versions of jars of any library in the classpath.

The packaging data is disabled by default.

<configuration packagingData="true"> ...
</configuration>

5.2. Clean Resources on Shutdown

In standalone applications, to correctly shutting down logback and releasing associated resources, use the shutdown hook. The hook will close all appenders attached to loggers defined by the context and stop any active threads in an orderly manner. It will allow up to 30 seconds for any log file compression tasks running in the background to finish.

<configuration debug="false">	<shutdownHook/>	....
</configuration>

A shutdown hook will be installed automatically in web applications, making this directive entirely redundant.

Обновление конфига на лету

Возможность такая есть из коробки: достаточно вызвать функцию-конфигуратор ещё раз, не забыв сделать там LoggerContext::reset() и очистку накопленного кэша.

Использование перехватчика завершения работы лога

Чтобы высвободить ресурсы логирования при завершении работы приложения, предусмотрен перехватчик завершения, который запускает очистку системы логирования при выходе из JVM. Этот перехватчик завершения регистрируется автоматически, если только ваше приложение не развернуто в виде war-файла. Если приложение имеет сложную иерархию контекстов, перехватчик завершения может не соответствовать вашим потребностям. Если он не соответствует им, отключите перехватчик завершения и рассмотрите варианты, предусмотренные непосредственно базовой системой логирования. Например, Logback прдусматривает контекстные селекторы, которые позволяют создавать каждый Logger в своем собственном контексте. Можно использовать свойство logging.register-shutdown-hook, чтобы отключить перехватчик завершения. Установка значения в false отключает регистрацию. Можно установить это свойство в файле application.properties или application.yaml:

logging.register-shutdown-hook=false

logging: register-shutdown-hook: false

Default Logging Configuration

private final Logger LOGGER = LoggerFactory.getLogger(this.getClass());
@RequestMapping("/")
public String home(Map<String, Object> model) {	LOGGER.debug("This is a debug message");	LOGGER.info("This is an info message");	LOGGER.warn("This is a warn message");	LOGGER.error("This is an error message");	model.put("message", "HowToDoInJava Reader !!");	return "index";
}

Start the application. Access the application in the browser and verify log messages in the console.

2017-03-02 23:33:51.318 INFO 3060 --- [nio-8080-exec-1] c.h.app.controller.IndexController : info log statement printed
2017-03-02 23:33:51.319 WARN 3060 --- [nio-8080-exec-1] c.h.app.controller.IndexController : warn log statement printed
2017-03-02 23:33:51.319 ERROR 3060 --- [nio-8080-exec-1] c.h.app.controller.IndexController : error log statement printed

• The default logging level is INFO because the debug log message is not present.
• Spring boot uses a fixed default log pattern configured in different base configuration files.

%clr{%d{yyyy-MM-dd HH:mm:ss.SSS}}{faint} %clr{${LOG_LEVEL_PATTERN}} %clr{${sys:PID}}{magenta}
%clr{---}{faint} %clr{[%15.15t]}{faint} %clr{%-40.40c{1.}}{cyan} %clr{:}{faint} %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD}

The above pattern prints these listed log message parts with respective color coding applied:

• Date and Time — Millisecond precision.
• Log Level — ERROR, WARN, INFO, DEBUG or TRACE.
• Process ID.
• A — separator to distinguish the start of actual log messages.
• Thread name — Enclosed in square brackets (may be truncated for console output).
• Logger name — This is usually the source class name (often abbreviated).
• The log message

Расширение формата своими переменными

Чтобы не городить свой огород, а воспользоваться проверенной инфраструктурой логбэка, нужно определить свой класс конвертера, обязательно целиком публичный чтобы его могли инстанциировать извне. Если нужен MDC, берём его из эвента. Здесь заводится обработчик переменной %custom:

 public class CustomConverter extends ClassicConverter { public String convert(ILoggingEvent event) { // mdc = event.getMDCPropertyMap(); return "variable-expanded"; } }

Во время общего процесса конфигурации зарегистрируем обработчик:

 void configurePatterns(LoggerContext lc) { Map<String, String> rules = lc.getObject(CoreConstants.PATTERN_RULE_REGISTRY); if (rules == null) { rules = new HashMap<String, String>(); lc.putObject(CoreConstants.PATTERN_RULE_REGISTRY, rules); } rules.put("custom", CustomConverter.class.getName()); }

И будем использовать в качестве энкодера, например, PatternLayoutEncoder, который сам всё подхватит. В данном случае переменная %custom раскроется в строку "variable-expanded".

Каждому методу свой уровень логгирования

В класс MultiAppender добавим проверку: если уровень события преодолевает порог заданный для метода, только тогда логгируем его:

 Map<String, Level> levelByMethod = new HashMap<>(); protected void append(ILoggingEvent event) { Level minLevel = levelByMethod.get(methodName); if (event.getLevel().levelInt >= minLevel.levelInt) { appender.doAppend(event); }

В принципе, эту логику можно вынести в фильтр.

Использование Lombok для ссылки на реализацию журналирования

Просто как подсказка, чтобы сэкономить время на вводе: мы можем использовать аннотацию Lombok, Slf4jчтобы указать ссылку на на реализацию журналирования:

@Service
@Slf4j
public class UserService { public String getUser(final String userID) { log.info("Service: Fetching user with id {}", userID); }
}

Ротация файлов

Если вы используете Logback, можно точно настроить параметры ротации лога с помощью файла application.properties или application.yaml. Для всех других систем логирования нужно будет самостоятельно конфигурировать параметры ротации (например, если вы используете Log4J2, то можете добавить файл log4j2.xml или log4j2-spring.xml).

Поддерживаются следующие свойства политики ротации:

Инструменты для логирования в Java

Из известных решений по логированию в Java можно выделить:

• log4j
• JUL — java.util.logging
• JCL — jakarta commons logging
• Logback
• SLF4J — simple logging facade for java

Обзорно рассмотрим каждое из них, а в практической части материала возьмем за основу связку Slf4j — log4j. Сейчас это может показаться странным, но не переживайте: к концу статьи все будет понятно.

System.err.println

Первоначально был, разумеется, System.err.println (вывод записи в консоль). Его и сейчас используют для быстрого получения лога при дебаге. Конечно, говорить о каких-то настройках здесь не приходится, поэтому просто запомним его и пойдем дальше.

Log4j

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

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

В log4j были возможности по конфигурации таким образом, чтобы можно было включить логирование в пакете com.example.type и выключить его в подпакете com.example.type.generic. Это позволяло быстро отсечь то, что нужно логировать, от того, что не нужно.

Здесь важно отметить, что есть две версии log4j: 1.2.х и 2.х.х, которые несовместимы друг с другом.

log4j добавил такое понятие как appender, то есть инструмент, с помощью которого записываются логи и layout — форматирование логов. Это позволяет записывать только то, что нужно и как нужно. Больше о appender поговорим чуть позже.

JUL — java.util.logging

Одно из ключевых преимуществ это решения — JUL включен в JDK (Java development kit). К сожалению, при его разработке за основу взяли не популярный log4j, а решение от IBM, что и повлияло на его развитие. По факту на данный момент JUL есть, но им никто не пользуется.

Из “такого себе”: в JUL уровни логирования отличаются от того, что есть в Logback, Log4j, Slf4j, и это ухудшает понимание между ними.

Создание логгера более менее похожее. Для этого нужно сделать импорт:

java.util.logging.Logger log = java.util.logging.Logger.getLogger(LoggingJul.class.getName());

Имя класса специально передается для того, чтобы знать, откуда идет логирование.

Начиная с Java 8, можно передавать Supplier<String>. Это помогает считать и создавать строку только в тот момент, когда это действительно нужно, а не каждый раз, как это было до этого.

Только с выходом Java 8 разработчики решили важные проблемы, после чего JUL по-настоящему стало возможно в использовании. А именно, методы с аргументом Supplier<String> msgSupplier, как показано ниже:

public void info(Supplier<String> msgSupplier) { log(Level.INFO, msgSupplier);
}

JCL — jakarta commons logging

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

Почему? Когда в проект добавлялись какие-то зависимости, они могли использовать логгер, отличный от логгера на проекте. Из-за этого они транзитивно добавлялись в проект, что создавало реальные проблемы при попытке все это собрать воедино.

К сожалению, обертка была очень бедна на функциональность и никаких дополнений не вносила.

Наверное, было бы удобно, если бы все использовали JCL для работы. Но на деле так не получалось, поэтому на данный момент применять JCL — не лучшая идея.

Logback

• улучшена производительность;
• добавлена нативная поддержка slf4j;
• расширена опция фильтрации.

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

<configuration> <appender name="FILE" class="ch.qos.logback.core.FileAppender"> <file>app.log</file> <encoder> <pattern>%d{HH:mm:ss,SSS} %-5p [%c] - %m%n</pattern> </encoder> </appender> <logger name="org.hibernate.SQL" level="DEBUG" /> <logger name="org.hibernate.type.descriptor.sql" level="TRACE" /> <root level="info"> <appender-ref ref="FILE" /> </root>
</configuration>

SLF4J — simple logging facade for java

log.debug("User " + user + " connected from " + request.getRemoteAddr());

if (log.isDebugEnabled()) { log.debug("User " + user + " connected from " + request.getRemoteAddr());
}

То есть вместо одной строки логирования предлагали писать 3(!). Логирование должно минимизировать изменения в коде, и три строки явно противоречили общему подходу.

У slf4j не было проблем совместимости с JDK и API, поэтому сходу возникло красивое решение:

log.debug("User {} connected from {}", user, request.getRemoteAddr());

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

Все поддерживаемые системы логирования могут иметь уровни ведения лога, установленные в Environment из Spring (например, в application.properties) с помощью logging.level.<logger-name>=<level>, где level – один из уровней, среди которых TRACE, DEBUG, INFO, WARN, ERROR, FATAL или OFF. Можно сконфигурировать root диспетчер логирования с помощью logging.level.root.

В следующем примере показаны возможные параметры логирования в application.properties:

logging.level.root=warn
logging.level.org.springframework.web=debug
logging.level.org.hibernate=error

logging: level: root: "warn" org.springframework.web: "debug" org.hibernate: "error"

Также можно установить уровни ведения лога с помощью переменных окружения. Например, LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB=DEBUG установит для org.springframework.web значение DEBUG.

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

Свой лог-файл на каждый метод

Создадим и не забудем зарегистрировать свой собственный аппендер:

 class MultiAppender extends AppenderBase<ILoggingEvent> { @Override protected void append(ILoggingEvent event) { method = event.getMDCPropertyMap().get(MDC_KEY_METHOD); Appender appender = getOrCreateAppender(method); appender.doAppend(event); }

Сам он почти ничего не делает, только делегирует логгирование пачке настоящих файловых аппендеров, по одному на каждый метод. Делегирует одному, самому подходящему. «Настоящие» аппендеры создаются по требованию, так:

 fileAppender = new FileAppender<ILoggingEvent>(); fileAppender.setContext(lc); fileAppender.setAppend(false); fileAppender.setEncoder(getOrCreateEncoderByMethod(lc, method)); fileAppender.setFile(logFileByMethod.get(method)); fileAppender.start();

Logback Configuration

3.1. Zero Configuration Defaults

By default, when no default configuration file is found, logback will add a ConsoleAppender to the root logger and this will log all the messages in the Console.

This is the equivalent configuration used by default.

<configuration debug="true"> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder> </appender> <root level="debug"> <appender-ref ref="STDOUT" /> </root>
</configuration>

3.2. Loading Configuration File

The default configuration is enough to get started and for POC purposes. But for production-grade applications, we need to configure different file loggers at suitable Log levels.

During startup, logback tries to locate logback-test.xml or logback.xml in the classpath, in the same order. If the file is found, it configures itself using the provided configuration file.

If no such file is present in classpath, it tries to locate the implementation of com.qos.logback.classic.spi.Configurator interface by looking up the file META-INF\services\ch.qos.logback.classic.spi.Configurator in the classpath for programmatic configuration.

If none of the file or Configurator implementation is found, it configures itself with default configuration, as discussed previously.

Note that may specify the location of the default configuration file with a system property or startup argument named “logback.configurationFile“. The value of this property can be a URL, a resource on the classpath or a path to a file external to the application.

3.3. Checking Initialization Errors

If we face any error during the logback initialization, we can set the debug="true" in the configuration tag. This will print status information to the console as it processes the configuration.

<configuration debug="true"> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> ... </appender> <root level="debug"> <appender-ref ref="STDOUT_ONE" /> </root>
</configuration>

18:34:34,556 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
18:34:34,556 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/C:/devsetup/gitrepo/opensource-examples/target/classes/logback.xml]
18:34:34,675 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
18:34:34,679 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
18:34:34,686 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
18:34:34,708 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG
18:34:34,708 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - Could not find an appender named [STDOUT1]. Did you define it below instead of above in the configuration file?
18:34:34,708 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - See https://logback.qos.ch/codes.html#appender_order for more details.
18:34:34,708 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
18:34:34,710 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@ec756bd - Registering current configuration as safe fallback point
18:34:34,712 |-WARN in Logger[com.howtodoinjava.demo.slf4j.Main] - No appenders present in context [default] for logger [com.howtodoinjava.demo.slf4j.Main].

3.4. Auto Reload Configuration File upon Modification

Set scan="true" to configuration tag to let logback scan for changes and automatically reconfigure itself when the configuration file changes.

In the background, a ReconfigureOnChangeTask runs in a separate thread and checks the config file on a defined interval. If the latest version of the configuration file has XML syntax errors, it will fall back to a previous configuration file free of XML syntax errors.

By default, the configuration file will be scanned for changes once every minute. To specify a different scanning period, set the scanPeriod attribute.

<configuration scan="true" scanPeriod="120 seconds" > ...
</configuration> 

If no unit of time is specified, then the unit of time is assumed to be milliseconds.

3.5. Conditional Configuration

Instead of defining multiple configuration files for different needs, we can put all configurations in a single file and add conditions around the relevant sections with the help of if, then and else tags.

For example, the given configuration will configure a console appender in the local development environment with debug logging enabled. Otherwise, the root logger will log all error messages in the provided file appended.

 <if condition='property("ENV").contains("localhost")'> <then> <appender name="CON" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d %-5level %logger{35} - %msg %n</pattern> </encoder> </appender> <root level="DEBUG"> <appender-ref ref="CON" /> </root> </then> </if> <root level="ERROR"> <appender-ref ref="FILE" /> </root>

Note that conditional processing requires the Janino library.

Консольный вывод

В конфигурации лога по умолчанию сообщения отражаются в консоль по мере их записи. По умолчанию в лог записываются сообщения уровней ERROR, WARN и INFO. Вы также можете активировать режим «отладки», запустив приложение с флагом --debug.

$ java -jar myapp.jar --debug

Также можно задать debug=true в файле application.properties.

Если режим отладки активирован, набор основных диспетчеров логирования (встроенный контейнер, Hibernate и Spring Boot) конфигурируется для вывода дополнительной информации. Активация режима отладки не конфигурирует приложение на регистрацию всех сообщений с уровнем DEBUG.

Кроме того, можно активировать режим «трассировки», запустив приложение с флагом --trace (или trace=true в файле application.properties). Это позволяет регистрировать лог трассировки для ряда основных диспетчеров логирования (встроенный контейнер, генерация схемы Hibernate и весь портфель Spring).

Вывод с цветовой подсветкой

Если терминал поддерживает ANSI, для облегчения чтения используется цветовой вывод. Можно установить spring.output.ansi.enabled в поддерживаемое значение чтобы переопределить автоматическое обнаружение.

Цветовое кодирование конфигурируется с помощью слова преобразования %clr. В своей простейшей форме преобразователь окрашивает вывод в соответствии с уровнем лога, как показано в следующем примере:

В следующей таблице описано соответствие уровней лога цветам:

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

%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){yellow}

Поддерживаются следующие цвета и стили:

Configuring Appenders

Logback delegates the task of writing a logging event to components called appenders. Appenders are responsible for outputting the logging events in a suitable format to the appropriate output device. However, they may delegate the actual formatting of the event to a Layout or to an Encoder object.

The configuration file must be a well-formed XML file, and all open tags must be closed properly.

4.1. ConsoleAppender

The console appender appends on the console, or more precisely on System.out or System.err.

Logback, by default, configures the console appender with DEBUG level. We can configure its attributes by defining the appender in logback.xml file.

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">	<encoder>	<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>	</encoder>
</appender>
<root level="INFO">	<appender-ref ref="STDOUT" />
</root>

4.2. RollingFileAppender

File appender appends log events into a file. If the file already exists, it is either appended to, or truncated depending on the value of the append property.

To log into the rolling files (based on time, log file size, or a combination of both), we use RollingFileAppender. The RollingPolicy is responsible for undertaking the actions required for a rollover, and TriggeringPolicy determines if and exactly when rollover occurs.

RollingPolicy implements the TriggeringPolicy interface so if we define only rollingPolicy then also configuration will be accepted.

<appender name="FILE"	class="ch.qos.logback.core.rolling.RollingFileAppender">	<file>${LOG_ROOT}/app.log</file>	<append>true</append>	<immediateFlush>false</immediateFlush>	<rollingPolicy	class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">	<!-- Archiving daily -->	<fileNamePattern>${LOG_ROOT}/app-%d{yyyy-MM-dd}.log.gz</fileNamePattern>	<!-- Archiving 60 days of logs and max 10GB size limit -->	<maxHistory>60</maxHistory>	<totalSizeCap>10GB</totalSizeCap>	</rollingPolicy>	<encoder>	<pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n	</pattern>	</encoder>
</appender>
<root level="INFO">	<appender-ref ref="FILE" />
</root>

Logback’s FileAppender and all its sub-classes, including RollingFileAppender, can gracefully recover from I/O failures. Thus, if a file server fails temporarily, we no longer need to restart the application to get logging working again. As soon as the file server comes back up, the logger will be working again.

By default, each log event is immediately flushed to the underlying output stream. In case of very high logging throughput, we can set the immediateFlush property to false.

Customize the Console Logs via Properties/YAML

Generally, in the console logs, we would want to do two things i.e. log levels and output pattern.

2.1. Log Levels

To change the log level, we can change it at two levels – root logger and/or specific logger instance.

To change the level at the root logger, ‘logging.level.root=trace‘ (with the desired level) in the properties file. Additionally, to control logging at individual logger level, use logging.level.LOGGER_NAME=trace.

logging.level.root=INFO
logging.level.org.springframework=ERROR
logging.level.org.hibernate=ERROR

2.2. Log Output Pattern

The pattern is controlled vis property logging.pattern.console and logging.pattern.file properties.

logging.pattern.console=%d{yyyy-MM-dd HH:mm:ss} - %logger{36} - %msg%n
logging.pattern.file=%d{yyyy-MM-dd HH:mm:ss} - %logger{36} - %msg%n

2.3. Log Thresholds

If we are using Logback or Log4j2, we can configure different log levels for console logs and file logs using the configuration properties logging.threshold.console and logging.threshold.file.

logging.threshold.console=TRACE
logging.threshold.file=INFO

Вывод в файл

По умолчанию Spring Boot ведет лог только в консоли и не ведет запись в файлы лога. Если необходимо осуществлять запись в файлы лога в дополнение к выводу в консоль, необходимо установить свойство logging.file.name или logging.file.path (например, в файле application.properties).

В следующей таблице показано, как свойства logging.* можно использовать вместе:5

Файлы лога ротируются, если их размер достигает 10 МБ, и, как и в случае с выводом в консоль, по умолчанию регистрируются сообщения уровней ERROR, WARN и INFO.

Свойства логирования не зависят от фактической инфраструктуры логирования. Следовательно, специфические конфигурационные ключи (например, logback.configurationFile для Logback) не находятся под управлением Spring Boot.

Logback Dependencies

To be up and running with logback requires three modules in the application runtime:

• logback-core: provides the main classes and interfaces needed by the other two modules.
• logback-classic: natively implements the SLF4J API.
• slf4j-api: logback-classic’s Logger class implements the SLF4J API. So we can readily switch back and forth between logback and other logging frameworks.
• logback-access (Optional) : integrates with Servlet containers, such as Tomcat and Jetty, to provide remote logging functionality.

<dependency>	<groupId>ch.qos.logback</groupId>	<artifactId>logback-core</artifactId>	<version>1.2.10</version>
</dependency>
<dependency> <groupId>ch.qos.logback</groupId> <artifactId>logback-classic</artifactId> <version>1.2.10</version>
</dependency>
<dependency>	<groupId>org.slf4j</groupId>	<artifactId>slf4j-api</artifactId>	<version>1.7.32</version>
</dependency>

Note that logback-classic will automatically pull in the logback-core and slf4j-api, so adding logback-classic dependency is enough.

Вывод

В этой статье мы увидели, как использовать ведение журнала в Spring Boot и как настроить его в соответствии с нашими требованиями. Но чтобы в полной мере использовать преимущества, возможности фреймворка по ведению журналов необходимо дополнить надежными и стандартизованными методами ведения журналов в ваших группах разработки.

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

Вы можете найти весь исходный код, использованный в статье на Github .

Disable the Console Logging

To disable logging in the console, the cleanest way is to create a custom logging configuration file (logback.xml or log4j2.xml) and not provide any definition of a console appender.

Only include file appenders in the configuration file which will prevent any logging output to the console.

<?xml version="1.0" encoding="UTF-8"?>
<configuration> <property name="LOG_LOCATION" value="c:/temp" /> <property name="LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss} – %logger{36} – %msg%n" /> <appender name="file" class="ch.qos.logback.core.FileAppender"> <file>${LOG_LOCATION}/mylog.log</file> <encoder> <pattern>${LOG_PATTERN}</pattern> </encoder> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>${LOG_LOCATION}/archived/mylog-%d{yyyy-MM-dd}.%i.log</fileNamePattern> <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP"> <maxFileSize>10MB</maxFileSize> </timeBasedFileNamingAndTriggeringPolicy> </rollingPolicy> </appender> <logger name="com.howtodoinjava.app" level="trace" additivity="false"> <appender-ref ref="file" /> </logger> <root level="info"> <appender-ref ref="file"/> </root>
</configuration>

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN" monitorInterval="30"> <Properties> <Property name="LOG_PATTERN">%d{yyyy-MM-dd’T’HH:mm:ss.SSSZ} %p %m%n</Property> </Properties> <RollingFile name="file" fileName="${APP_LOG_ROOT}/SpringBoot2App/application.log" filePattern="${APP_LOG_ROOT}/SpringBoot2App/application-%d{yyyy-MM-dd}-%i.log"> <PatternLayout pattern="${LOG_PATTERN}" /> <Policies> <SizeBasedTriggeringPolicy size="19500KB" /> </Policies> <DefaultRolloverStrategy max="1" /> </RollingFile> <Loggers> <Root level="info"> <AppenderRef ref="file" /> </Root> </Loggers>
</Configuration>

If not using configuration files, we can use the property logging.pattern.console with empty value to disable console logging. It is not the recommended approach and do it only for POCs.

logging.pattern.console=

Drop me your questions related to Spring boot console appender example.

Happy Learning !!

Запись и отправка логов

Этот процесс будем рассматривать на примере log4j: он предоставляет широкие возможности для записи/отправки логов:

• для записи в файл — решение DailyRollingFileAppender;
• для получения данных в консоль приложения — ConsoleAppender;
• для записи логов в базу данных — JDBCAppender;
• для контроля передачи через TCP/IP — TelnetAppender;
• для того, чтобы запись логов не била по быстродействию — AsyncAppender.

Есть еще несколько реализаций: полный список можно получить здесь.

Кстати, если нужного аппендера не будет, это не проблема. Можно написать свой аппендер, имплементировав интерфейс Appender, который как раз принимает log4j.

Logging to File Appender

To print the logs in the file, use logging.file or logging.path property.

logging.file=c:/users/howtodoinjava/application-debug.log

Verify the logs in the file.

2017-03-03 13:02:50.608 DEBUG 10424 --- [http-nio-8080-exec-1] c.h.app.controller.IndexController : This is a debug message
2017-03-03 13:02:50.608 INFO 10424 --- [http-nio-8080-exec-1] c.h.app.controller.IndexController : This is an info message
2017-03-03 13:02:50.608 WARN 10424 --- [http-nio-8080-exec-1] c.h.app.controller.IndexController : This is a warn message
2017-03-03 13:02:50.609 ERROR 10424 --- [http-nio-8080-exec-1] c.h.app.controller.IndexController : This is an error message

Подведем итоги

1. Мы поговорили о том, какие бывают решения в Java.
2. Почти все известные библиотеки по логированию написали под управлением одного человека 😀
3. Мы узнали, что нужно логировать, а что не стоит.
4. Разобрались с уровнями логирования.
5. Познакомились с узлами логирования.
6. Рассмотрели, что такое аппендер и для чего он.
7. Поэтапно настроили log4j.proterties файл.

Закрепим результат

Попробуйте проделать все описанное самостоятельно:

• Создайте свой проект по типу того, что есть в примере выше.
• Если есть знания использования Maven — используем, если нет, то вот ссылка на статью, где описано как подключить библиотеку.

Custom Console Logging using logback. xml

If we have configured logging via logback – using own logback.xml file then use the below configuration to control various options of console logging.

<?xml version="1.0" encoding="UTF-8"?>
<configuration> <property name="LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss} – %logger{36} – %msg%n" /> <appender name="console" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>${LOG_PATTERN}</pattern> </encoder> </appender> <logger name="com.howtodoinjava.app" level="trace" additivity="false"> <appender-ref ref="console" /> </logger> <root level="info"> <appender-ref ref="console"/> </root>
</configuration>

Custom Console Logging using log4j2. xml

To configure console logging with log4j2, place the given definition in log4j2.xml file.

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN" monitorInterval="30"> <Properties> <Property name="LOG_PATTERN">%d{yyyy-MM-dd’T’HH:mm:ss.SSSZ} %p %m%n</Property> </Properties> <Appenders> <Console name="console" target="SYSTEM_OUT"> <PatternLayout pattern="${LOG_PATTERN}" /> </Console> </Appenders> <Loggers> <Root level="info"> <AppenderRef ref="console" /> </Root> </Loggers>
</Configuration>

Conclusion

We also saw the best practices that can help use Logback most effectively.

Happy Learning !!

Литература

Официальный мануал logback