Logback и Log4j2 – одни из самых известных фреймворков логирования в JAVA. Фреймворк Logback используется только совместно с библиотекой SLF4J, которая представляет собой интерфейс для систем протоколирования событий. Log4j2 представляет собой вторую, улучшенную версию логгера Log4, библиотеку логирования, в которой интерфейс API и реализация выделены отдельно, что позволяет использовать API Log4j 2 совместно с реализацией другого логгера.

Spring Music является приложением для использования сервиса базы данных среды Cloud Foundry совместно со Spring Framework и Spring Boot. Оно создано для сохранения одних и тех же доменных объектов в одном из множества различных хранилищ – объектно-реляционном, документно-ориентированном или распределенном (key-value store).



Двумя наиболее распространенными логгерами, которые используются совместно со Spring / Spring Boot, являются Logback и Log4j2. Еще недавно разработчик имел большую свободу действий в отношении формата логов и самих файлов, используемых для ведения журнала. Однако в современном мире внедрения контейнеров и масштабирования логирование обычно предлагает корпоративные решения, требующие определенного уровня стандартизации.

Одна из самых больших проблем заключается в том, что исключения Java обычно приводят к большой многострочной трассировке стека в журналах. Из-за этого вместо одного события журнала, указывающего на исключение, или сообщение об ошибке, у вас возникает более 100 различных логов, по одному на каждую строку трассировки стека, перемежающихся другими событиями журнала, поступающими от других служб или экземпляров служб.

В этой статье рассказывается, как настроить приложение Spring Boot для свертывания исключений в одну строку как для логгера Logback, так и для Log4j2. Это позволяет рассматривать логирование исключения и трассировку стека как один лог событий.


Классы ошибок Error и исключений Exception в JAVA


Проверяемые Checked и непроверяемые Unchecked исключения Exception в JAVA

Приложение Spring Music


В этой статье для специализированного логирования используется кастомная версия приложения spring-music,  необходимая для работы логгеров Logback и Log4j2. Для начала нужно убедиться, что мы сможем воссоздать ее из источника. Проект требует наличия Java8, поэтому первым шагом является установка Java8 на ваш хост Ubuntu.



Затем мы берем исходный код проекта с github и создаем сборку с использованием встроенных скриптов системы сборки Gradle:



Свертывание многострочных исключений с использованием Logback


Двинемся дальше и создадим Java-архив проекта jar с реализацией логгера Logback с помощью стандартной команды Gradle:



Файл “build/libs/spring-music.jar” является самоисполняемым и содержит встроенный Tomcat, который привязан к localhost:8080. Вызов jar-файла осуществляется с помощью команды:



Вызов http://localhost:8080 в браузере покажет вам страницу со списком Альбомов, а в консоль будет выведена строка лога, выглядящая таким образом:



Этот синтаксис строки лога определен в “src/main/resources/logback-spring.xml” с использованием пользовательского шаблона:



Переменные ${…} извлекаются из application.properties и system properties, которые можно просмотреть на странице по адресу http://localhost:8080/env. Однако нужная нам часть кода находится сразу после сообщения (%m).



Слово ‘MULTIEXCEPTION’ не имеет особого значения, это просто уникальный строковый маркер, который позволяет нам узнать, где заканчивается сообщение (%m) и начинается исключение. Если хотите, то можете оставить этот маркер.

Далее, вместо того, чтобы просто вставлять заполнитель %xException, который выводил бы большую трассировку стека с символами новой строки, мы преобразуем значение при помощи функции %replace и заменяем все символы новой строки на выражение “\u2028”, которое является представлением разделителя строк Unicode.

Удаление символов "\n" из трассировки стека означает, что теперь трассировка стека теперь будет отправляться в однострочном виде. Чтобы доказать это, перейдите по ссылке http://localhost:8080/errors/throw, где имеется Error Controller, который намеренно отбрасывает NullPointerException с помощью следующего кода:



Это создает в консоли строку лога, показанную ниже:



Здесь видно, что выражение «u2028» отделяет то, что раньше было переводом строки в трассировке стека. Теперь сообщение об исключении и трассировка стека будут отправлены как единое целое.



Свертывание многострочных исключений с использованием Log4j2


Чтобы переопределить сценарий сборки по умолчанию и использовать Log4j2 в качестве резервной реализации данного проекта, нужно использовать файл “build-log4j2.gradle”.



Файл “build/libs/spring-music.jar” является самоисполняемым и использует встроенный Tomcat, который привязан к localhost:8080. Как и в предыдущем примере, вызов jar-файла осуществляется с помощью команды:



Вызов http://localhost:8080 с помощью браузера отобразит страницу со списком Альбомов с выводом на консоль строки лога, которая выглядит следующим образом:



Этот синтаксис строки журнала определен в “src/main/resources/log4j2.xml” с использованием кастомного шаблона:



Переменные ${…} извлекаются из application.properties и system properties, которые можно просмотреть на странице по адресу http://localhost:8080/env. Однако нужная нам часть кода находится сразу после сообщения (%m).



Слово ‘MULTIEXCEPTION’ не имеет специального значения, это просто уникальный строковый маркер по нашему выбору, который позволяет узнать, где заканчивается сообщение (%m) и начинается исключение. Если хотите, то можете его оставить.

Но после этого вместо того, чтобы просто вставлять заполнитель %xException, который выводил бы большую трассировку стека с символами новой строки, мы преобразуем значение при помощи функции %replace, которая заменяет все символы новой строки выражением “\u2028”, которое является представлением разделителя строк Unicode.

Удаление символов "\n" из трассировки стека означает, что теперь трассировка стека теперь будет отправляться в виде одной строки. Чтобы доказать это, перейдите по ссылке http://localhost:8080/errors/throw, где имеется Error Controller, который намеренно отбрасывает NullPointerException с помощью следующего кода:



Это создает в консоли строку лога, показанную ниже:



Как можно увидеть, здесь выражение «u2028» отделяет то, что раньше было переводом строки в трассировке стека. Теперь сообщение об исключении и трассировка стека будут отправляться как единое целое.

Выводы


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

При этом символ Unicode всегда может быть заменен на стороне сбора логов (например, на стороне конвейера для сбора, фильтрации и нормализации логов Logstash) для восстановления сообщения в исходном формате.

Ссылочный материал



Немного рекламы :)


Спасибо, что остаётесь с нами. Вам нравятся наши статьи? Хотите видеть больше интересных материалов? Поддержите нас, оформив заказ или порекомендовав знакомым, облачные VPS для разработчиков от $4.99, уникальный аналог entry-level серверов, который был придуман нами для Вас: Вся правда о VPS (KVM) E5-2697 v3 (6 Cores) 10GB DDR4 480GB SSD 1Gbps от $19 или как правильно делить сервер? (доступны варианты с RAID1 и RAID10, до 24 ядер и до 40GB DDR4).

Dell R730xd в 2 раза дешевле в дата-центре Equinix Tier IV в Амстердаме? Только у нас 2 х Intel TetraDeca-Core Xeon 2x E5-2697v3 2.6GHz 14C 64GB DDR4 4x960GB SSD 1Gbps 100 ТВ от $199 в Нидерландах! Dell R420 — 2x E5-2430 2.2Ghz 6C 128GB DDR3 2x960GB SSD 1Gbps 100TB — от $99! Читайте о том Как построить инфраструктуру корп. класса c применением серверов Dell R730xd Е5-2650 v4 стоимостью 9000 евро за копейки?

Комментарии (9)


  1. rmuskovets
    05.01.2020 15:15

    В названии опечатка — Spring, не Sprnig.


    1. foxyrus
      05.01.2020 18:17
      -1

      Ctrl+Enter


  1. schroeder
    05.01.2020 16:02

    вы решили проблему не с той стороны: не проще ли писать логи в json формате, как собственно и положено делать в 2020 году?


    1. ladutsko
      05.01.2020 17:25

      Спорное заявление!
      Json избыточен. Форматирование отнимает ресурсы у биснеса. Логирование в консоль нечитаемое. Как то так …


      1. endymion
        05.01.2020 17:34

        Вот ни разу не спорное. json per line формат широко распространен и супер-удобен при централизации логов. Настроить логирование в json в том-же spring-boot — дело двух минут:


        build.gradle.kts:


        configurations {
            all {
                exclude("org.springframework.boot", "spring-boot-starter-logging")
            }
        }
        
        dependencies {
          implementation("org.springframework.boot:spring-boot-starter-log4j2")
        }

        log4j2-spring.xml:


        <?xml version="1.0" encoding="UTF-8"?>
        <Configuration status="WARN">
            <Appenders>
                <Console name="Console" target="SYSTEM_OUT" follow="true">
                    <JsonLayout compact="true" eventEol="true" properties="false" stacktraceAsString="true">
                        <!-- Zipkin
                        <KeyValuePair key="trace" value="$${ctx:X-B3-TraceId:-}"/>
                        <KeyValuePair key="span" value="$${ctx:X-B3-SpanId:-}"/>
                        <KeyValuePair key="parent" value="$${ctx:X-B3-ParentSpanId:-}"/>
                        <KeyValuePair key="exportable" value="$${ctx:X-Span-Export:-}"/>
                        -->
                    </JsonLayout>
                </Console>
            </Appenders>
            <Loggers>
        
                <Logger name="io.micrometer" level="warn"/>
                <Logger name="org.apache.kafka" level="warn"/>
                <Logger name="org.hibernate.validator" level="warn"/>
                <Logger name="org.springframework" level="warn"/>
        
                <Root level="info">
                    <AppenderRef ref="Console"/>
                </Root>
            </Loggers>
        </Configuration>


  1. ladutsko
    05.01.2020 17:39

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


  1. Urgen
    06.01.2020 00:28

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


    1. Anthrax_Beta
      07.01.2020 10:13

      В кибану, например, попадает только первая строка сообщения.


      1. YuryB
        07.01.2020 15:38

        а спланк всё понимает, но по-моему строки больше 10к обрезает по дефолту