Динамические уровни ведения журналов: небольшие функции, широкое использование

Java задняя часть Apache Log4j
Динамические уровни ведения журналов: небольшие функции, широкое использование

⚠️Эта статья является первой подписанной статьей сообщества Nuggets, перепечатка без разрешения запрещена.


Log4j, Log4j2 и Logback являются текущими основными платформами ведения журналов, а Slf4j — это новое поколение интерфейсов среды ведения журналов.Logback напрямую реализует интерфейс Slf4j, а также является средой ведения журналов по умолчанию в SpringBoot.

Но с точки зрения производительности и инженерии,Log4j2Является стандартом де-факто, эта статья также основана на Log4j2 для написания.


Зачем нужны динамические уровни логов

оLog4j2Немного знаний о существительных:

  • Метод конфигурации: в промышленных проектах обычно используются методы конфигурации XML.
  • Синхронный/асинхронный: Log4j2 поддерживает синхронное/асинхронное ведение журнала.Если нет специального сценария, рекомендуется использовать высокопроизводительный асинхронный метод.
  • Logger: узел Logger — это элемент конфигурации, используемый для отдельного указания формы представления журнала, включая, помимо прочего: уровень журнала, связанный Appender, атрибут Name и т. д.
  • Appender: Appender обычно отвечает только за запись данных события в целевую цель, а Logger запускает указанный Appender для выполнения.

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

Большую часть времени журнал является инструментом, помогающим нам найти проблему, но у всего есть две стороны, и иногда это может стать проблемой.предохранитель проблемы.


Интерфейс необъяснимо медленный?

Вообще говоря, время отклика интерфейса в основном тратится на сеть, уровень БД, уровень ввода-вывода или часть вычислений, но когда я проверил онлайн-проблему на стороне B, я обнаружил, что весь интерфейс был перетащен печатью. бревно.

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

Определить эту необъяснимую проблему просто:

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

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


Онлайн-раздача процессоров

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

 log.info("Method :: Kerwin.Demo, Params: {}, Result:{}", JSONUtil.toJsonStr(demo), JSONUtil.toJsonStr(demo));

Это включает в себя операции сериализации.Когда количество таких журналов велико и количество вызовов интерфейса велико (сотни тысяч вызовов C-стороны в минуту), использование ЦП значительно возрастет, даже если нет проблем со всем программа .


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


Как динамически настраивать уровни журналов

отLog4j2Например, мы можем настроить корневой узел (ROOT Logger) следующим образом.

<Loggers>
    <AsyncRoot level="ERROR" includeLocation="true">
        <AppenderRef ref="INFO_LOG"/>
        <AppenderRef ref="ERROR_LOG"/>
    </AsyncRoot>
</Loggers>

Используйте следующий код и просмотрите файл журнала

@Slf4j
public class LogTest {
    public static void main(String[] args) {
        log.info("This is a Demo...");
    }
}

image-20210809000506403.png

Поскольку я настроил уровень журнала ROOT наERROR, поэтому лог не выводится

Используя возможности Log4j2, измените уровень журнала следующим образом:

@Slf4j
public class LogTest {
    public static void main(String[] args) {
        log.info("This is a Demo... 111");
        Level level = Level.toLevel("info");
        LoggerContext context = (LoggerContext) LogManager.getContext(false);
        Configuration configuration = context.getConfiguration();
        configuration.getLoggerConfig("ROOT").setLevel(level);
        context.updateLoggers(configuration);
        log.info("This is a Demo... 222");
    }
}

Результат выглядит следующим образом:

image-20210809001159978.png

Очень легко реализовать возможность изменения уровня журнала, поэтому, когда мы создаем собственные приложения или системы, мы можем использоватьZKДля динамической конфигурации вы также можете использоватьHTTP- или RPC-интерфейсОставьте заднюю дверь, чтобы добиться возможности динамической настройки.


Как настроить уровень журнала указанного класса

В приведенном выше коде показано, как динамически настроить узел ROOT Logger.Если вы можете использовать IDE во время чтения этой статьи, вы, естественно, увидите

org.apache.logging.log4j.core.config.Configuration#getLoggers, этот метод включает параметры конфигурации каждого пользовательского регистратора, которые также можно настроить и изменить с помощью вышеуказанных методов.

Пример кода:

String packetLoggerName = "log.demo";
Level level = Level.toLevel("DEBUG");
LoggerContext context = (LoggerContext) LogManager.getContext(false);
Configuration configuration = context.getConfiguration();
for (Map.Entry<String, LoggerConfig> entry : configuration.getLoggers().entrySet()) {
    if (packetLoggerName.equals(entry.getKey())) {
        entry.getValue().setLevel(level);
    }
}

context.updateLoggers(configuration);

На следующем рисунке показана наша конфигурация уровня журнала:

image-20210809002325350.png


Сомнение: как фреймворк обрабатывает классы без регистраторов

Вывод первый:

  1. Каждый регистратор не обязательно имеет соответствующую конфигурацию.
  2. Фактически работающий Logger не обязательно является самим собой, как указано выше:log.demo.test.LogTestApp
  3. Между Регистраторами существует наследование, т.е.log.demo.test.LogTestAppВ случае отсутствия другой дополнительной конфигурации будет использоваться родительская конфигурация:log.demo, и так далее, покаROOT

Используйте следующую конфигурацию и код для проверки:

 <Loggers>
     <AsyncRoot level="INFO" includeLocation="true">
         <AppenderRef ref="Console"/>
     </AsyncRoot>

     <logger name="log.demo" level="ERROR">
         <AppenderRef ref="ERROR_LOG"/>
     </logger>
</Loggers>
@Slf4j
public class LogTestApp {
    public static void main(String[] args) {
        System.out.println(log.getName());
    }
}

// 输出结果
// log.demo.test.LogTestApp

Наблюдая за файлом конфигурации, мы можем ясно обнаружить, что вся структура ведения журнала на самом деле не существует:log.demo.test.LogTestAppЭтот регистратор, как он работает?

Анализ основного кода выглядит следующим образом:

private static final Logger log = LoggerFactory.getLogger(LogTestApp.class);

Через фабричный метод для создания всего пути к исходному коду можно найти класс:AbstractConfiguration

@Override
public LoggerConfig getLoggerConfig(final String loggerName) {
    LoggerConfig loggerConfig = loggerConfigs.get(loggerName);
    if (loggerConfig != null) {
        return loggerConfig;
    }
    String substr = loggerName;
    while ((substr = NameUtil.getSubName(substr)) != null) {
        loggerConfig = loggerConfigs.get(substr);
        if (loggerConfig != null) {
            return loggerConfig;
        }
    }
    return root;
}

Роль этого метода состоит в том, чтобы дать каждому классуLoggerсвязать фактическоеИсполнительГде метод NameUtil.getsubname() получает предыдущий слой текущего класса, находит недавний проход по циклу (так называемая недавняя граница имени, по подродителю)Logger.

После понимания вышеперечисленных характеристик у нас также есть ответ на вопрос.


Настройте родительский Logger по запросу

С развитием техники иерархия системных кодов очень очевидна.На примере нашей компании она в основном делится на:Дао, Сервис, Бизнес, АпиЧетыре уровня, на которых обычно размещается основной бизнесBusinessУровень, поэтому проблема также возникает на бизнес-уровне при нормальных обстоятельствах, мы можем настроить следующееLoggerДинамически регулировка всех уровней регистрации бизнеса, чтобы добиться более точного контроля:

<Loggers>
    <logger name="com.jd.o2o.business" level="INFO">
        <!-- INFO_LOG -->
    </logger>
</Loggers>

Точно так же, если вам нужно обратить внимание на уровень БД, вы также можете настроить родительский Logger для мониторинга журналов уровня БД.


Генерировать Logger динамически

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

Читая исходный код, мы видим, что следующие методы могут соответствовать нашим требованиям:

org.apache.logging.log4j.core.config.Configuration#addLogger

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


Сомнение: необъяснимый вывод

Иногда мы также сталкиваемся с этой проблемой:Я хочу, чтобы он печатал журнал ERROR для определенного Logger и выводил его только в файл ERROR.В результате он выводит в INFO и ERROR.Почему это?

На самом деле это проблема дизайна фреймворка ведения журнала.Основной код выглядит следующим образом:

private void processLogEvent(final LogEvent event, final LoggerConfigPredicate predicate) {
    event.setIncludeLocation(isIncludeLocation());
    if (predicate.allow(this)) {
    	callAppenders(event);
    }
    logParent(event, predicate);
}

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

Соблюдайте следующий код, чтобы найти решение:

// 核心代码
private void logParent(final LogEvent event, final LoggerConfigPredicate predicate) {
    if (additive && parent != null) {
        parent.log(event, predicate);
    }
}

// 解决办法 additivity置为false
<logger name="log.demo" level="INFO" additivity="false"></logger>

Советы по печати журналов

В дополнение к правильной печати в журнале использования также есть несколько небольших советов, таких как:

  • Вариант первый:

    log.info("This is a Demo, Request:{}", JSONUtil.toJsonStr(new LogTest()));
    
  • Вариант 2:

    if (log.isInfoEnabled()) {
        log.info("This is a Demo, Request:{}", JSONUtil.toJsonStr(new LogTest()));
    }
    

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


Суммировать

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

Итак, как эффективно использовать структуру ведения журнала, вот несколько советов:

  1. Используйте Slf4j для моста, чтобы избежать прямого использования конкретной среды ведения журналов.
  2. Разумная настройка RootLogger и его подчиненных Logger может выводить системно-зависимые журналы уровня фреймворка в указанные файлы, что удобно для устранения неполадок.
  3. Разумное использование возможности динамических уровней ведения журналов для корректировки уровней онлайн-журналов в любое время.
  4. Уменьшите поведение сериализации в журнале.При использовании журналов низкого уровня необходимо определить, включен ли текущий уровень журнала, чтобы избежать ненужной сериализации.
  5. Если особых сценариев нет, попробуйте использовать асинхронные журналы с высокой пропускной способностью.

Если вы считаете этот контент полезным:

  1. Конечно, ставьте лайки и поддерживайте~
  2. Кроме того, вы можете искать и следить за официальной учетной записью "это Кервин», давайте вместе пойдем по дороге технологий~ 😋