2010-10-13 3 views
39

Я прочитал тонны сообщений и документов (на этом сайте и в других местах), указывая, что рекомендуемый шаблон для регистрации SFL4J является:Почему вызов LoggerFactory.getLogger (...) каждый раз не рекомендуется?

public class MyClass { 
    final static Logger logger = LoggerFactory.getLogger(MyClass.class); 

    public void myMethod() { 
     //do some stuff 
     logger.debug("blah blah blah"); 
    } 
} 

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

public class MyLoggerWrapper { 
    public static void debug(Class clazz, String msg){ 
     LoggerFactory.getLogger(clazz).debug(msg)); 
    } 
} 

и просто использовать его как это:

public class MyClass { 

    public void myMethod() { 
     //do some stuff 
     MyLoggerWrapper.debug(this.getClass(), "blah blah blah"); 
    } 
} 

Я полагаю, создание экземпляра журнала каждый раз, когда мы регистрируемся, несколько дороже, но я не смог найти документацию, подтверждающую это предположение. Кроме того, он уверен, что рамки (LogBack или Log4J, которые мы все еще решаем) будут «кэшировать» регистраторы, а также, что в любом случае серверы работают значительно ниже их емкости, поэтому это не проблема.

Любая помощь, указывающая на потенциальные проблемы с этим подходом?

+2

Еще один момент: ваши линии регистрации становятся уродливыми с помощью метода босса, поскольку правильный синтаксис протоколирования - «MyLoggerWrapper.debug (MyClass.class,« blah blah blah »); –

+0

Спасибо Бенуа, вот что я намеревался показать, но в спешке на почту я сделал опечатку. Это просто пример, но мы будем использовать что-то вроде: MyLoggerWrapper.debug (это.getClass(), «blah») – danirod

+0

, но со статическим импортом у вас есть хорошая отладка (...) :) – Guillaume

ответ

3

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

Вы можете рассмотреть возможность просмотра веб-контейнера Jetty, который содержит собственную абстракцию, которая строится поверх slf4j. Очень хорошо.

11

Объекты регистратора, безусловно, используются повторно, поэтому никакой дополнительной информации не произойдет в любом случае. Чем больше проблема, которую я вижу, что ваш файл/строка информация число будет бесполезно, так как регистратор будет всегда точно войти, что каждое сообщение было выдано из класса LoggerWrapper, строка 12 :-(

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

+3

должен указать, что включение номера строки в выходном файле журнала чрезвычайно slow –

+1

Также следует указать, что имя класса также передается для идентификации используемого регистратора (в приведенном выше примере). Таким образом, ваша первая точка решена. – Noremac

+0

@Noremac, справедливо, имя класса будет занесено в журнал правильно. Тем не менее, я сильно подозреваю, что номер строки все равно будет неправильным. –

28

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

Стандартная идиома с log4j/Обще-каротаж/SLF4J заключается в использовании пункта охраны, такие как:

if (log.isDebugEnabled()) log.debug("blah blah blah"); 

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

if (log.isDebugEnabled()) log.debug("the result of method foo is " + bar 
    + ", and the length is " + blah.length()); 

См "What is the fastest way of (not) logging?" in the SLF4J или log4j FAQ.

Я бы рекомендовал против «обертки», который предлагает ваш босс. Библиотека, подобная slf4j или commons-logging, уже является фасадом вокруг фактической базовой реализации каротажа. Кроме того, каждый вызов регистратора становится гораздо более длительным - сравните выше с

MyLoggerWrapper.debug(Foo.class, "some message"); 

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

+6

+1 для упоминания оговорки охраны - это важный момент. –

+3

Хорошо, он больше похож на ведущего/ведущего программиста команды ;-) Оговорка о защите уже позаботилась, используя параметризованные сообщения - как описано в вашей ссылке и других документах, которые я прочитал, - мы просто применяем необходимые методы в обертке по мере необходимости. Согласитесь с уродством вызовов журнала обертки(), но я пока не должен быть убежден в любом из ответов здесь, что это хуже, чем создание экземпляра журнала для каждого класса, что является болью в шее, и тоже некрасиво. – danirod

+5

Я не уверен, что я согласен с тем, что одна строка кода для каждого класса для 'final static Logger logger = LoggerFactory.getLogger (MyClass.class)' все это уродливо. Используя вашу IDE по выбору, легко придумать простой шаблон/макрос, чтобы вы могли добавить этот фрагмент к файлу всего несколькими нажатиями клавиш. Однако красота в глазах смотрящего ... –

10

Повторные вызовы LoggerFactory.getLogger(clazz) не должны приводить к появлению нового объекта Logger каждый раз. Но это не означает, что призывы бесплатны. Хотя фактическое поведение зависит от системы ведения журнала за фасадом, весьма вероятно, что каждый getLogger влечет за собой поиск в параллельной или синхронизированной структуре данных для поиска уже существующего экземпляра.

Если ваше приложение делает много звонков на ваш метод MyLoggerWrapper.debug, все это может значительно повысить производительность. И в многопоточном приложении это может быть узким местом параллелизма.

Другие вопросы, упомянутые другие ответы также важны:

  • Ваше приложение больше не может использовать logger.isDebugEnabled(), чтобы минимизировать накладные расходы при отладке отключена.
  • Класс MyLoggerWrapper скрывает имена классов и номера строк отладочных вызовов приложения.
  • Код с использованием MyLoggerWrapper, вероятно, будет более подробным, если вы сделаете несколько вызовов журнала. И многословие будет в той области, где оно больше всего влияет на читаемость; то есть в методах, которые выполняют операции, требующие регистрации.

Наконец, это просто «не так, как это делается».


1 - По-видимому, в Logback и Log4j Hashtable, и это означает, что потенциал для параллелизма узкого места, безусловно, существует. Обратите внимание, что это не критика этих фреймворков. Скорее, метод getLogger не был разработан/оптимизирован для использования таким образом.

+0

Обратите внимание, что накладные расходы на поиск уже существующих экземпляров регистратора могут включать, в частности, синхронизацию. E. g. logback использует Hashtable для кэширования журналов, который является синхронизированным словарем. Синхронизация будет происходить при каждом вызове вашей логгирующей оболочки независимо от того, что сообщение регистрируется или нет. Я бы сказал, что это может легко убить любое приложение с высоким трафиком. – lost

+0

@ lost - Хорошая точка. Я включил это в свой ответ. –

4

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

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

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

9

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

  • Это заставляет вас постоянно что-то типа, что не имеет никакого отношения с лесозаготовок, каждый раз, когда вы хотите что-то войти: this.getClass()
  • Создает неравномерный интерфейс между статическими и нестационарными контекстами (поскольку в статическом контексте нет)
  • Дополнительные ненужные параметры создают место для ошибки, позволяют операторам того же класса перейти на разные лесорубы (подумайте о небрежности c opy)
  • Пока он сохраняет 74 символа объявления регистратора, он добавляет 27 дополнительных символов к каждому вызову регистрации. Это означает, что если класс использует регистратор более 2 раз, вы увеличиваете код шаблона с точки зрения количества символов.
+1

+1 для небрежного копирования и других. – Reddy

6

При использовании что-то вроде: MyLoggerWrapper.debug (this.getClass(), «л») вы получите неправильные имена классов при использовании АОПА или инструментов коды впрыска. Классовые имена не похожи на исходное, а сгенерированное имя класса. И еще один недостаток использования оболочки: для каждого оператора журнала вы должны добавить дополнительный код «MyClass.class».

«Кэширование» регистраторов зависит от используемых фреймворков. Но даже когда он это делает, он все равно должен искать нужный регистратор для каждые Заявление о регистрации, которое вы делаете. Таким образом, имея 3 оператора в методе, он должен искать его 3 раза. Используя его как статическую переменную, он должен искать его только один раз!

И сказал ранее: вы теряете возможность использовать if (log.isXXXEnabled()) {} для набора инструкций.

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

5

Здесь есть одна возможность упростить ведение журнала в Java 8 - определить интерфейс, чтобы сделать это за вас. Например:

package logtesting; 

import java.util.Arrays; 

import org.slf4j.Logger; 
import org.slf4j.LoggerFactory; 

public interface Loggable { 
    enum LogLevel { 
     TRACE, DEBUG, INFO, WARN, ERROR 
    } 

    LogLevel TRACE = LogLevel.TRACE; 
    LogLevel DEBUG = LogLevel.DEBUG; 
    LogLevel INFO = LogLevel.INFO; 
    LogLevel WARN = LogLevel.WARN; 
    LogLevel ERROR = LogLevel.ERROR; 

    default void log(Object...args){ 
     log(DEBUG, args); 
    } 

    default void log(final LogLevel level, final Object...args){ 
     Logger logger = LoggerFactory.getLogger(this.getClass()); 
     switch(level){ 
     case ERROR: 
      if (logger.isErrorEnabled()){ 
       logger.error(concat(args)); 
      } 
      break; 
     case WARN: 
      if (logger.isWarnEnabled()){ 
       logger.warn(concat(args)); 
      } 
      break;   
     case INFO: 
      if (logger.isInfoEnabled()){ 
       logger.info(concat(args)); 
      } 
     case TRACE: 
      if (logger.isTraceEnabled()){ 
       logger.trace(concat(args)); 
      } 
      break; 
     default: 
      if (logger.isDebugEnabled()){ 
       logger.debug(concat(args)); 
      } 
      break; 
     } 
    } 

    default String concat(final Object...args){ 
     return Arrays.stream(args).map(o->o.toString()).collect(Collectors.joining()); 
    } 
} 

Тогда все, что вы когда-либо сделать, это убедиться, что ваши классы объявить реализации Записан, и любой из них, вы можете сделать что-то вроде:

log(INFO, "This is the first part ","of my string ","and this ","is the last"); 

лога () позаботится о том, чтобы конкатенировать ваши строки, но только после того, как он проверяет на включение. Он регистрируется для отладки по умолчанию, и если вы хотите вести журнал для отладки, вы можете опустить аргумент LogLevel. Это очень простой пример. Вы можете сделать все возможное, чтобы улучшить это, например, реализовать отдельные методы, то есть error(), trace(), warn() и т. Д. Вы также можете просто реализовать «logger» как функцию, которая возвращает регистратор:

public interface Loggable { 
    default Logger logger(){ 
     return LoggerFactory.getLogger(this.getClass()); 
    } 
} 

И тогда становится довольно тривиально использовать регистратор:

logger().debug("This is my message"); 

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

package logtesting; 

import org.slf4j.Logger; 
import org.slf4j.LoggerFactory; 
import org.slf4j.Marker; 

public interface Loggable extends Logger { 
    default Logger logger(){ 
     return LoggerFactory.getLogger(this.getClass()); 
    } 

    default String getName() { 
     return logger().getName(); 
    } 

    default boolean isTraceEnabled() { 
     return logger().isTraceEnabled(); 
    } 

    default void trace(String msg) { 
     logger().trace(msg); 
    } 

    default void trace(String format, Object arg) { 
     logger().trace(format, arg); 
    } 

    default void trace(String format, Object arg1, Object arg2) { 
     logger().trace(format, arg1, arg2); 
    } 

    default void trace(String format, Object... arguments) { 
     logger().trace(format, arguments); 
    } 

    default void trace(String msg, Throwable t) { 
     logger().trace(msg, t); 
    } 

    default boolean isTraceEnabled(Marker marker) { 
     return logger().isTraceEnabled(marker); 
    } 

    default void trace(Marker marker, String msg) { 
     logger().trace(marker, msg); 
    } 

    default void trace(Marker marker, String format, Object arg) { 
     logger().trace(marker, format, arg); 
    } 

    default void trace(Marker marker, String format, Object arg1, Object arg2) { 
     logger().trace(marker, format, arg1, arg2); 
    } 

    default void trace(Marker marker, String format, Object... argArray) { 
     logger().trace(marker, format, argArray); 
    } 

    default void trace(Marker marker, String msg, Throwable t) { 
     logger().trace(marker, msg, t); 
    } 

    default boolean isDebugEnabled() { 
     return logger().isDebugEnabled(); 
    } 

    default void debug(String msg) { 
     logger().debug(msg); 
    } 

    default void debug(String format, Object arg) { 
     logger().debug(format, arg); 
    } 

    default void debug(String format, Object arg1, Object arg2) { 
     logger().debug(format, arg1, arg2); 
    } 

    default void debug(String format, Object... arguments) { 
     logger().debug(format, arguments); 
    } 

    default void debug(String msg, Throwable t) { 
     logger().debug(msg, t); 
    } 

    default boolean isDebugEnabled(Marker marker) { 
     return logger().isDebugEnabled(marker); 
    } 

    default void debug(Marker marker, String msg) { 
     logger().debug(marker, msg); 
    } 

    default void debug(Marker marker, String format, Object arg) { 
     logger().debug(marker, format, arg); 
    } 

    default void debug(Marker marker, String format, Object arg1, Object arg2) { 
     logger().debug(marker, format, arg1, arg2); 
    } 

    default void debug(Marker marker, String format, Object... arguments) { 
     logger().debug(marker, format, arguments); 
    } 

    default void debug(Marker marker, String msg, Throwable t) { 
     logger().debug(marker, msg, t); 
    } 

    default boolean isInfoEnabled() { 
     return logger().isInfoEnabled(); 
    } 

    default void info(String msg) { 
     logger().info(msg); 
    } 

    default void info(String format, Object arg) { 
     logger().info(format, arg); 
    } 

    default void info(String format, Object arg1, Object arg2) { 
     logger().info(format, arg1, arg2); 
    } 

    default void info(String format, Object... arguments) { 
     logger().info(format, arguments); 
    } 

    default void info(String msg, Throwable t) { 
     logger().info(msg, t); 
    } 

    default boolean isInfoEnabled(Marker marker) { 
     return logger().isInfoEnabled(marker); 
    } 

    default void info(Marker marker, String msg) { 
     logger().info(marker, msg); 
    } 

    default void info(Marker marker, String format, Object arg) { 
     logger().info(marker, format, arg); 
    } 

    default void info(Marker marker, String format, Object arg1, Object arg2) { 
     logger().info(marker, format, arg1, arg2); 
    } 

    default void info(Marker marker, String format, Object... arguments) { 
     logger().info(marker, format, arguments); 
    } 

    default void info(Marker marker, String msg, Throwable t) { 
     logger().info(marker, msg, t); 
    } 

    default boolean isWarnEnabled() { 
     return logger().isWarnEnabled(); 
    } 

    default void warn(String msg) { 
     logger().warn(msg); 
    } 

    default void warn(String format, Object arg) { 
     logger().warn(format, arg); 
    } 

    default void warn(String format, Object... arguments) { 
     logger().warn(format, arguments); 
    } 

    default void warn(String format, Object arg1, Object arg2) { 
     logger().warn(format, arg1, arg2); 
    } 

    default void warn(String msg, Throwable t) { 
     logger().warn(msg, t); 
    } 

    default boolean isWarnEnabled(Marker marker) { 
     return logger().isWarnEnabled(marker); 
    } 

    default void warn(Marker marker, String msg) { 
     logger().warn(marker, msg); 
    } 

    default void warn(Marker marker, String format, Object arg) { 
     logger().warn(marker, format, arg); 
    } 

    default void warn(Marker marker, String format, Object arg1, Object arg2) { 
     logger().warn(marker, format, arg1, arg2); 
    } 

    default void warn(Marker marker, String format, Object... arguments) { 
     logger().warn(marker, format, arguments); 
    } 

    default void warn(Marker marker, String msg, Throwable t) { 
     logger().warn(marker, msg, t); 
    } 

    default boolean isErrorEnabled() { 
     return logger().isErrorEnabled(); 
    } 

    default void error(String msg) { 
     logger().error(msg); 
    } 

    default void error(String format, Object arg) { 
     logger().error(format, arg); 
    } 

    default void error(String format, Object arg1, Object arg2) { 
     logger().error(format, arg1, arg2); 
    } 

    default void error(String format, Object... arguments) { 
     logger().error(format, arguments); 
    } 

    default void error(String msg, Throwable t) { 
     logger().error(msg, t); 
    } 

    default boolean isErrorEnabled(Marker marker) { 
     return logger().isErrorEnabled(marker); 
    } 

    default void error(Marker marker, String msg) { 
     logger().error(marker, msg); 
    } 

    default void error(Marker marker, String format, Object arg) { 
     logger().error(marker, format, arg); 
    } 

    default void error(Marker marker, String format, Object arg1, Object arg2) { 
     logger().error(marker, format, arg1, arg2); 
    } 

    default void error(Marker marker, String format, Object... arguments) { 
     logger().error(marker, format, arguments); 
    } 

    default void error(Marker marker, String msg, Throwable t) { 
     logger().error(marker, msg, t); 
    } 
} 

Конечно, как уже упоминалось ранее, это означает, что каждый раз, когда вы входите, вы должны будете пройти через процесс поиска Logger в вашем LoggerFactory - если вы не переопределить метод логгер() ... в которой вы также можете сделать это «рекомендуемым» способом.

+0

Это неплохая идея, но если вы используете Java 8 с этим удивительным средством Closures, почему мы должны иметь эти предложения охраны? В вашем коде каждый раз, когда журнал называется защитой, если вызывать вызовы и операторы switch. Однако с закрытием (или даже полиморфизмом в целом) вы можете создать новый класс регистратора при запуске приложения, который имеет пустые методы для уровней журнала под уровнем конфигурации (через файл свойств). –

+1

Вы действительно можете это сделать. Но призывы к этому методу будут STILL конкатенировать все строковые аргументы, если в сторожевых предложениях нет ..., что является целым рядом с использованием объектов varargs, а не для передачи встроенного строкового сообщения. Вы можете обойти это, но, честно говоря, вызов isErrorEnabled() не заметно менее эффективен, чем вызов метода пустой ошибки() ... и точка интерфейса заключается в том, что вам больше не придется беспокоиться о инструкциях guard. Вы написали их один раз, и вы избавились от беспокойства о них навсегда. –

+0

@Steve K Мне нравится это решение У меня есть что-то похожее, есть ли производительность для постоянного вызова getLogger (this.getClass())? – Selwyn

0

я, возможно, пропустили его в одном из предыдущих комментариев, но я не видел упоминания о том, что регистратор статический, вызов LoggerFactory производится СРАЗУ (в конкретизации класса) - поэтому начальное беспокойство о множественных вызовах для создания регистратора просто неверно.

Другие комментарии по всем вопросам с добавлением классов упаковки также очень важны.

3

Как указано here командой SLF4J, вы можете использовать MethodLookup(), представленную в JDK 1.7.

final static Logger logger = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); 

Таким образом, вы можете обратиться к классу без использования ключевого слова «это».

1

Есть две причины, по которым подход вашего босса не достигает того, что он думает.

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

  • Найдите класс, т. Е. Пройдете все jar и каталоги. Java-код. Довольно большие накладные расходы из-за вызовов файловой системы. Может создавать вспомогательные объекты, например. с File.
  • Загрузите байт-код, то есть скопируйте его в структуру данных внутри JVM. Родной код.
  • Подтвердить байт-код. Родной код.
  • Ссылка на байт-код, т. Е. Перебирает все имена классов в байт-коде и заменяет их указателями на упомянутый класс. Родной код.
  • Запустить статические инициализаторы. Исправлено из собственного кода, инициализаторы - это Java-код, конечно. Здесь создается Logger.
  • Через некоторое время, возможно, JIT-компиляция класса. Родной код. Огромный накладные расходы (по сравнению с другими операциями в любом случае).

Кроме того, ваш босс ничего не спасает.
Первый вызов LoggerFactor.getLogger создаст регистратор и поместит его в глобальное имя-на-журнал HashMap. Это произойдет даже для вызовов isXxxEnabled, потому что для этого вам нужно сначала создать объект Logger ...
В объекте Class будет добавлен дополнительный указатель на статическую переменную. Это компенсируется накладными расходами на передачу параметра clazz - дополнительной инструкции и дополнительной ссылки указателя в байтовом коде, поэтому вы потеряете хотя бы один байт в размере класса.

Код также проходит через дополнительную ссылку, LoggerFactory.getLogger(Class) использует Class#getName и делегирует LoggerFactory.getLogger(String).

Теперь, если ваш босс не работает, но после возможности просто скопировать статическое объявление, он может использовать функцию, которая проверяет стек вызовов и извлекает имя класса. Функция должна быть аннотирована @CallerSensitive, и это все равно что-то, что нужно тестировать всякий раз, когда используется новая JVM - нехорошо, если вы не контролируете JVM, на котором пользователь запускает код.

Наименее проблематичным подходом было бы иметь IDE, которая проверяет экземпляр регистратора. Это, вероятно, означает поиск или запись плагина.

Смежные вопросы