Обязательно ли передавать в метод getlogger имя класса почему так принято



Скачай курс
в приложении
Перейти в приложение
Открыть мобильную версию сайта
© 2013 — 2023. Stepik
Наши условия использования и конфиденциальности

Public user contributions licensed under cc-wiki license with attribution required
Логирование в Java / quick start
В ходе моей работы в компании DataArt я, в числе прочего, занимаюсь менторской деятельностью. В частности это включает в себя проверку учебных заданий сделанных практикантами. В последнее время в заданиях наметилась тенденция «странного» использования логеров. Мы с коллегами решили включить в текст задания ссылку на статью с описанием java logging best practices, но оказалось, что такой статьи в которой бы просто и без лишних деталей на практике объяснялось бы как надо писать в лог на Java, вот так вот с ходу не находится.
Данная статья не содержит каких-то откровений, в ней не рассматриваются тонкости какого либо из многочисленных java logging frameworks. Здесь рассказываю как записать в лог так, чтобы это не вызвало удивления у Ваших коллег, основная цель написания включить ее в список обязательного чтения для практикантов. Если все еще интересно, читайте дальше
- Весь код примеров использует java.util.logging framework. Вопрос «Какой из фреймворков логирования ниболее кошерен» я оставлю за кадром. Скажу только что до java.util.logging проще всего дотянуться ибо он уже идет вместе с JRE и на самом деле рассказанное в данной статье с минимальными косметическими правками верно для подавляющего большинства систем логирования.
- В целом рецепты приведенные в данной статье не являются единственно верными, есть моменты о которых можно поспорить, но в целом эти рецепты используются многие годы, многими разработчиками, во многих проектах и они достаточно хороши чтобы им следовать если у Вас нет каких-то совсем уже серьезных возражений.
- В статье не рассматриваются такие «продвинутые» топики как:
- Конфигурирование уровней для отдельных логеров
- Форматирования логов
- Асинхронное логирование
- Создание собственных уровней логирования в Log4J
- Контекстное логирование
- И многое другое
Пример №1
Хорошо
public class SomeClass < private static Logger log = Logger.getLogger(SomeClass.class.getName()); public void someMethod() < log.info("Some message"); >.- Логер это статическое поле класса инициализируемое при загрузке класса, имеет простое, короткое имя, важно чтобы во всех Ваших классах переменная логера называлась одинаково (это диктуется общим правилом, одинаковые вещи в программе должны делаться одинаковым образом).
- В качестве имени логера я использую имя класса, на самом деле это не единственный способ, можно пытаться организовать какую-то свою иерархию логирования (например transport layer/app layer для подсистем имеющих дело с обменом данными), но как показывает практика выдумывать и главное потом неукоснительно следовать такой иерархии крайне сложно, а вариант с именами логеров совпадающими с именами классов весьма хорош и используется в 99% проектов
- Здесь для записи в лог я использую короткий метод .info, а не более общий метод .log, так много лаконичнее
- Имя логера берется как SomeClass.class.getName(), а не как «com.dataart.demo.java.logging.SomeClass», оба способа по идее одинаковы, но первый защищает Вас от сюрпризов при рефакторинге имени/пакета класса
Плохо
public class SomeClass < public void someMethod() < Logger.getLogger("com.dataart.demo.java.logging.SomeClass").log(Level.INFO,"Some message"); >.По сути тоже самое но букв больше и читается не так легко.
Замечание между примерами
Вы наверное обратили внимание, что все сообщения в примерах на английском языке. Это не случайно. Дело в том, что даже если все-все кто работает и будет работать с Вашим кодом говорят по русски, есть вероятность, что Вам придется просматривать лог сообщения на удаленном компьютере например через ssh при этом в большом количестве случаев Вы увидите примерно такое сообщение «. . . » (я безусловно знаю что через ssh можно протащить русские буквы, но вот почему-то далеко не всегда все оказывается настроенным должным образом).
Или даже на локальной машине в cmd вы можете увидеть что вот такое:
INFO: ╨Ъ╨░╨║╨╛╨╡-╤В╨╛ ╤Б╨╛╨╛╨▒╤Й╨╡╨╜╨╕╨╡ ╨▓ ╨╗╨╛╨│С этим безусловно тоже можно бороться. Но не всегда легко объяснить заказчику на том конце телефонной трубки, как сделать так чтобы вместо крякозябр были видны русские буквы.
Совет: Пишите лог сообщения на английском языке, ну или в крайнем случае латинскими буквами.Пример №2
Хорошо
try < throw new Exception("Some exception"); >catch (Exception ex) < log.log(Level.SEVERE, "Exception: ", ex); >//В стандартной лог конфигурации вы это сообщение не увидите log.fine("some minor, debug message"); /* Иногда вывод лог сообщений требует достаточно больших ресурсов (например дамп какого-то пакета данных и т.п.). В таких случаях стоит проверить выведется ли в лог сообщение для этого уровня логирования */ if (log.isLoggable(Level.FINE))- Если Вам необходимо залогировать исключение, для этого служит метод .log(level,message,exception)
- Если вы специально не настроили конфигурацию лог системы, сообщения с уровнем ниже info, например fine выводиться не будут. Но писать их по крайней мере для важных частей системы стоит. Когда что-то пойдет не так, Вы настроите более подробный уровень логирования и увидите много интересного.
- Слишком много лог сообщений, даже если они физически не пишутся в лог файл из-за своего слишком маленького уровня, могут существенно замедлить выполнение программы. Особенно если для подготовки самого сообщения надо потратить много ресурсов. Для этого есть метод .isLoggable(level) — он позволяет узнать пропустит ли текущая конфигурация логера данное сообщение
Плохо
try < throw new Exception("Some exception"); >catch (Exception ex) < log.severe("Exception: " + ex.toString() ); >log.fine("Some CPU consuming message: " + itTakes500MillisecondsToPrepageThisMessage());Если логировать только ex.toString(), то потом Вы не сможете понять в какой строке изначально сработало исключение.
Пример №3
Логер надо конфигурировать. Есть конфигурация по умолчанию она выводит в консоль все сообщения с уровнем INFO и выше. Она достаточно хороша, для разработки из IDE, но для реального приложения ее обычно неплохо бы подправить.
Какие тут есть варианты
По умолчанию: Файл logging.properties для уровня INFO, вывод в консоль
#Console handler
handlers= java.util.logging.ConsoleHandler
.level=INFOДелаем логирование более подробным выводим еще и сообщения уровня FINE
#Console handler
handlers= java.util.logging.ConsoleHandler
.level=FINE
java.util.logging.ConsoleHandler.level = FINE- Установили уровень FINE для корневого логера, просто чтобы сообщения пролезали внутрь лог системы.
- И сказали что все что пролезет через лог систему надо выводить на консоль от уровня FINE и выше.
Выводим лог сообщения куда-то еще
- Если приложение запускается с помощью javaw Вы вообще ничего не увидите.
- Если вывод идет в консоль и нужное вам сообщение промелькнуло 4 часа назад буфер консоли его уже съел, информация пропала.
- Если вывод консоли направлен в файл java com.yourcompanyname.EntryClass 2>>application_log.txt и приложение работает не останавливаясь несколько недель — файл будет весьма и весьма большим, рискуя занять весь диск.
Чтобы решить эти проблемы был придуман java.util.logging.FileHandler — хэндлер который выводит лог сообщения в файл. При этом он умеет ротировать файлы, т.е. после достижения максимально допустимого размера, он дописывает в файл текщуее лог сообщение и открывает новый файл с инкрементальным префиксом. И так по кругу. Например
handlers= java.util.logging.FileHandler java.util.logging.FileHandler.pattern = application_log.txt java.util.logging.FileHandler.limit = 50 java.util.logging.FileHandler.count = 7 java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter
создаст вот такие файлы (последняя колонка — размер в байтах)
application_log.txt.0 │ 0 application_log.txt.1 │ 79 application_log.txt.2 │ 79 application_log.txt.3 │ 676 application_log.txt.4 │ 87 application_log.txt.5 │ 114
Мы указали максимальный размер 50 байтов, в реальной жизни надо скорее указывать не меньше мегабайта, например вот так (я знаю, что 1000000 это чуть меньше мегабайта, но кому охота по памяти писать 1048576, если суть дела это фактически не меняет)
java.util.logging.FileHandler.limit = 1000000
В примере, как мы видим, файлы получились больше 50 байт потому что размер по сути округляется вверх до последнего целого лог сообщения. Т.е. если Вы укажете размер 1 байт и запишете лог сообщение размером в 1000 байт то размер файла станет 1000 байт и после этого лог сообщения файл закроется и откроется следующий.
copy & paste конфиг для реальной жизни, его вполне хватает для большинства service, console и desktop приложений.
handlers= java.util.logging.FileHandler java.util.logging.FileHandler.pattern = application_log.txt java.util.logging.FileHandler.limit = 1000000 java.util.logging.FileHandler.count = 5 java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter
Последняя часть магии
- Из командной строки запуска приложения
- В первых строчках кода Вашего приложения
Первый чуть более правильный ибо он декларативный и работает сразу, до того как начал работать код Вашего приложения.
Вот так
java Djava.util.logging.config.file=logging.properties com.dataart.application.ClassName
Но к сожалению менять строку запуска не всегда можно или не всегда удобно. Второй способ тоже неплохо работает.
public static void main(String[] args) < try < LogManager.getLogManager().readConfiguration( MainApplicationEntryClass.class.getResourceAsStream("/logging.properties")); >catch (IOException e) < System.err.println("Could not setup logger configuration: " + e.toString()); >.
- Здесь MainApplicationEntryClass — это класс — точка входа в Ваше приложение, видимо имя класса у Вас будет другое
- Сам файл logging.properties как правило в таких случаях кладется в корень иерархии классов и выглядит это например вот так
Что осталось за кадром
- Log4J
- JULI logger (строго говоря это не вполне самостоятельный фреймворк, а своего рода надстройка над java.util.logging)
- SLF4J
- Commons Logging
- Tomcat
- JBoss
- Resin
Логирование в Java: что, как, где и чем?

Давайте разберем реальные случаи, в которых логирование решало бы проблему. Вот пример из моей работы. Есть точки приложений, которые интегрируются с другими сервисами. Я использую логирование этих точек для “алиби”: если интеграция не сработает, будет легко разобраться, с какой стороны возникла проблема. Еще желательно логировать важную информацию, которая сохраняется в базу данных. Например создание пользователя администратора. Это как раз то, что хорошо бы логировать.
Инструменты для логирования в 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
. Это помогает считать и создавать строку только в тот момент, когда это действительно нужно, а не каждый раз, как это было до этого. Только с выходом Java 8 разработчики решили важные проблемы, после чего JUL по-настоящему стало возможно в использовании. А именно, методы с аргументом Supplier msgSupplier , как показано ниже: public void info(Supplier msgSupplier)
JCL — jakarta commons logging
Из-за того, что долгое время не было промышленного стандарта в логировании и был период, когда многие создавали свой кастомный логгер, решили выпустить JCL — общую обертку, которая использовалась бы над другими. Почему? Когда в проект добавлялись какие-то зависимости, они могли использовать логгер, отличный от логгера на проекте. Из-за этого они транзитивно добавлялись в проект, что создавало реальные проблемы при попытке все это собрать воедино. К сожалению, обертка была очень бедна на функциональность и никаких дополнений не вносила. Наверное, было бы удобно, если бы все использовали JCL для работы. Но на деле так не получалось, поэтому на данный момент применять JCL — не лучшая идея.
Logback
- улучшена производительность;
- добавлена нативная поддержка slf4j;
- расширена опция фильтрации.
app.log %d %-5p [%c] - %m%n SLF4J — simple logging facade for java
Где-то в 2006 году один из отцов-основателей log4j вышел из проекта и создал slf4j — Simple Logging Facade for Java — обертку вокруг log4j, JUL, common-loggins и logback. Как видим, прогресс дошел до того, что создали обертку над оберткой… Причем она делится на две части: API, который используется в приложении и реализация, которая добавляется отдельными зависимостями для каждого вида логирования. Например, slf4j-log4j12.jar , slf4j-jdk14.jar . Достаточно подключить правильную реализацию и все: весь проект будет работать с ней. Slf4j поддерживает все новые функции, такие как форматирование строк для логирования. До этого была такая проблема. Допустим, есть запись в лог:
log.debug("User " + user + " connected from " + request.getRemoteAddr());В объекте user происходит неявное преобразование user.toString() из-за конкатенации строк, и это занимает время, которое тормозит систему. И все ок, если мы дебажим приложение. Проблемы начинаются, если для этого класса уровень логирования INFO и выше. То есть этот лог не должен быть записан, и конкатенация строк также не должна быть произведена. По идее это должна была решить сама библиотека логирования. Причем это и оказалось самой большой проблемой первой версии log4j. Решения нормального не завезли, а предложили делать вот так:
if (log.isDebugEnabled())
То есть вместо одной строки логирования предлагали писать 3(!). Логирование должно минимизировать изменения в коде, и три строки явно противоречили общему подходу. У slf4j не было проблем совместимости с JDK и API, поэтому сходу возникло красивое решение:
log.debug("User <> connected from <>", user, request.getRemoteAddr());где <> обозначают вставки аргументов, которые передаются в методе. То есть первая <> соответствует user , вторая <> — request.getRemoteAddr() . Благодаря чему, только в случае, если уровень логирования позволяет записывать в лог, это сообщение конкатенировать в единое. После этого SJF4J стал быстро расти в популярности, и на данный момент это лучшее решение. Поэтому будем рассматривать логирование на примере связки slf4j-log4j12 .
Что нужно логировать
- Начало/конец работы приложения. Нужно знать, что приложение действительно запустилось, как мы и ожидали, и завершилось так же ожидаемо.
- Вопросы безопасности. Здесь хорошо бы логировать попытки подбора пароля, логирование входа важных юзеров и т.д.
- Некоторые состояния приложения. Например, переход из одного состояния в другое в бизнес процессе.
- Некоторая информация для дебага, с соответственным уровнем логирования.
- Некоторые SQL скрипты. Есть реальные случаи, когда это нужно. Опять-таки, умелым образом регулируя уровни, можно добиться отличных результатов.
- Выполняемые нити(Thread) могут быть логированы в случаях с проверкой корректной работы.
Популярные ошибки в логировании
- Избыток логирования. Не стоит логировать каждый шаг, который чисто теоретически может быть важным. Есть правило: логи могут нагружать работоспособность не более, чем на 10%. Иначе будут проблемы с производительностью.
- Логирование всех данных в один файл. Это приведет к тому, что в определенный момент чтение/запись в него будет очень сложной, не говоря о том, что есть ограничения по размеру файлов в определенных системах.
- Использование неверных уровней логирования. У каждого уровня логирования есть четкие границы, и их стоит соблюдать. Если граница расплывчатая, можно договориться какой из уровней использовать.
Уровни логирования
x: Visible FATAL ERROR WARN INFO DEBUG TRACE ALL OFF FATAL x ERROR x x WARN x x x INFO x x x x DEBUG x x x x x TRACE x x x x x x ALL x x x x x x x - OFF: никакие логи не записываются, все будут проигнорированы;
- FATAL: ошибка, после которой приложение уже не сможет работать и будет остановлено, например, JVM out of memory error;
- ERROR: уровень ошибок, когда есть проблемы, которые нужно решить. Ошибка не останавливает работу приложения в целом. Остальные запросы могут работать корректно;
- WARN: обозначаются логи, которые содержат предостережение. Произошло неожиданное действие, несмотря на это система устояла и выполнила запрос;
- INFO: лог, который записывает важные действия в приложении. Это не ошибки, это не предостережение, это ожидаемые действия системы;
- DEBUG: логи, необходимые для отладки приложения. Для уверенности в том, что система делает именно то, что от нее ожидают, или описания действия системы: “method1 начал работу”;
- TRACE: менее приоритетные логи для отладки, с наименьшим уровнем логирования;
- ALL: уровень, при котором будут записаны все логи из системы.
Запись и отправка логов: Appender
- для записи в файл — решение DailyRollingFileAppender;
- для получения данных в консоль приложения — ConsoleAppender;
- для записи логов в базу данных — JDBCAppender;
- для контроля передачи через TCP/IP — TelnetAppender;
- для того, чтобы запись логов не била по быстродействию — AsyncAppender.
Узлы логирования
Для демонстрации будем использовать интерфейс 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 будем смотреть, как их настроить.
Пошаговая настройка 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.
Закрепим результат
- Создайте свой проект по типу того, что есть в примере выше.
- Если есть знания использования Maven — используем, если нет, то вот ссылка на статью, где описано как подключить библиотеку.
Подведем итоги
- Мы поговорили о том, какие бывают решения в Java.
- Почти все известные библиотеки по логированию написали под управлением одного человека 😀
- Мы узнали, что нужно логировать, а что не стоит.
- Разобрались с уровнями логирования.
- Познакомились с узлами логирования.
- Рассмотрели, что такое аппендер и для чего он.
- Поэтапно настроили log4j.proterties файл.
Дополнительные материалы
- JavaRush: Логирование. Размотать клубок стектрейса
- JavaRush: Logger lecture
- Хабр: Java logging. Hello world
- Хабр: Java logging: история кошмара
- Youtube: Головач курсы. Логирование. Часть 1, Часть 2, Часть 3, Часть 4
- Log4j: appender
- Log4j: layout
- Как тестовое задание на собеседование превратилось в open-source библиотеку
- Создание системы мониторинга цен на авиабилеты: пошаговое руководство [Часть 1]
- Гайд по созданию клиента для Skyscanner API и его публикации в jCenter и Maven Central [Часть 1]
- Debug в Intellij IDEA: гайд для новичков
Обязательно ли передавать в метод getlogger имя класса почему так принято
Последнее изменение: 22 июня 2010г.
Ведение лога приложения
I like to log it, log it!
Суровая правда жизни
Если бы мы жили в мире, где обитают сферические программисты в вакууме – этой статьи бы не было. Ибо речь у нас пойдет о таком явлении, как ведение журнала действий приложения. В просторечии – лога 1 .
Для чего нужен лог? К сожалению, у несферических программистов приложений без ошибок не бывает. И чем сложнее приложение – тем больше в нем потенциально содержится ошибок. В общем-то это аксиома, но напомнить нелишне. И, что более важно, – чем сложнее приложение, тем изощреннее могут быть ошибки в нем. В том смысле, что произошедшая в данную секунду ошибка может быть вызвана событиями, произошедшими час назад. А то и день назад. Или же вообще – ошибок вроде как и нет, но система все равно ведет себя неадкеватно – на нажатие каждой кнопки реагирует секунд по 8-10, хотя еще два часа назад время реакции не превышало полсекунды.
А когда система в боевых условиях регулярно падает (совсем, насмерть!) без объявления войны, а в тестовых условиях такое поведение не воспроизводится никоим образом – хочется кого-нибудь убить. Чаще всего себя, ибо именно мне и предстоит решать эту проблему. Причем вчера.
Собственно, что объединяет все описаные случаи – во всех них сильно помогла бы информация о происходящих в системе событиях. Причем информация за определенный промежуток времени. Понимание этого факта и породила такое явление как ведение лога (журнала, протокола, – называйте как хотите) действий приложения.
Вот, что мы будем обсуждать:
- Типы логов и требования к ним
- Унифицированные системы логирования
- Log4J
- java.util.logging
- Apache Commons Logging
- Simple Logging Facade for Java
- Logback
- Краткое резюме
- Принципы и понятия
- Логгер
- Аппендер
- org.apache.log4j.FileAppender
- org.apache.log4j.RollingFileAppender
- org.apache.log4j.varia.ExternallyRolledFileAppender
- org.apache.log4j.DailyRollingFileAppender
- org.apache.log4j.SimpleLayout
- org.apache.log4j.HTMLLayout
- org.apache.log4j.xml.XMLLayout
- org.apache.log4j.TTCCLayout
- org.apache.log4j.PatternLayout / org.apache.log4j.EnhancedPatternLayout
- Инициализация Log4J
- Использование логгеров
- NDC – Nested Diagnostic Context
- MDC – Mapped Diagnostic Context
Типы логов и требования к ним
Принципиально логи нужны не только для отслеживания программых ошибок – точно так же можно отслеживать и ошибки (а то и целенаправленные действия) пользователей. Формально протокол действий приложения можно разделить на несколько частей. Если говорить об очень общем делении, то таких частей будет две – что происходит в приложения с точки зрения бизнес-пользователя и что происходит в приложение с точки зрения разработчика (программиста). Если смотреть в несколько другой плоскости – можно поделить все действия на системные (SYSTEM) , безопасности (SECURITY) и приложения (APPLICATION, BUSINESS). Так, например, классифицируются системные события в Windows семейства NT.
Поясню на примерах. Пользователь входит в приложение, проверяется пароль. Это действие относится к безопасности. Дальше он запускает какой-нибудь модуль приложения, например, работу с заявками на кредиты. Это действие приложения (BUSINESS). Модуль при старте обращается к другому модулю за какими-то дополнительными данными, производит какие-либо еще телодвижения – это уже системные действия.
Из всего перечисленного нас – разработчиков – интересует прежде всего то, что происходит в системе с точки зрения именно разработчика. Во всяком случае обсуждать мы будем только это. Что же касается классификации происходящих событий – SYSTEM/SECURITY/APPLICATION – разработчикам приходится иметь дело со всеми ними. Ниже мы рассмотрим, как эти логи можно разделять для удобства анализа.
Дальше. Простой вопрос – а сколько информации нам нужно? Такой же простой ответ – чем больше, тем лучше! – не годится. Ибо чем больше мы выводим информации о происходящем в системе – тем больше процессорного времени тратится на эти бесполезные с точки зрения конечного пользователя действия, и тем меньше остается собственно на работу. У меня в практике был случай, когда интенсивный вывод в лог – ошиблись в конфигурации – замедлил работу системы более чем в 50 раз. Вот тут на самом деле есть противоречие – с точки зрения пользователя логов должно быть в минимальном объеме, а с точки зрения разработчика – в максимальном. Ну и если мечтать – идеальной была бы ситуация, когда количество выводимых данных можно было бы менять как нужно, и в тот момент, когда нужно.
Следующее очевидное требование – вывод только той информации, которая нам нужна, и в том виде, в котором она нам нужна. Т.е. необходима возможность управлять форматом вывода – что именно выводить, мы и так контролируем. Причем крайне желательно, чтобы такая настройка была отделена от приложения – чтобы ее можно было менять, не трогая программного кода.
Не будь требования об универсальности, все было бы намного проще. Думаю, вы сами прекрасно понимаете, что идея ведения лога не нова. И, соответственно, реализована она во многих имеющихся операционных системах. На всякий случай не говорю «во всех», хотя уверенность в этом почти стопроцентная. Правда, реализована эта идея сильно по-разному. В *NIX это сервис syslog, в Windows семейства NT – NT Event Viewer. В других системах есть свои механизмы. И далеко не всегда результат их работы удобен для использования.
В общем, как ни крути – необходима унифицированная, гибко настраиваемая система для ведения лога. Эта система должна быть отделена от приложения, конфигурироваться отдельно от него, в идеале – вообще на лету. И такие системы есть. Правда, с ними иногда возникает путаница, потому в следующей часты мы рассмотрим, что есть что.
Унифицированные системы логирования
В настоящий момент лично я знаю три 2 фреймворка для ведения лога – библиотека Log4J, пакет java.util.logging в JavaSE и библиотека Logback. Помимо них мы рассмотрим два, я бы так выразился, «зонтичных» фреймворка – Apache Commons Logging и Simple Logging Facade for Java. Эти фреймворки являются прослойками между системой логирования и самим приложением.
Итак, начнем по хронологии.
Log4J
Фреймворк Apache Log4J появился первым из всех рассматриваемых. Если мне не изменяет память, до версии 1.2.8 он был совместим с Java 1.1. Изначально этот фреймворк был хорошо архитектурно проработан, потому он быстро завоевал популярность. Возможно, определенную роль сыграл также факт, что других просто не было.
Далее мы рассмотрим этот фреймворк в деталях, потому более подробно описывать его сейчас не буду. Хочу только сказать, что этот фреймворк очень популярен и по сей день.
java.util.logging
Пакет java.util.logging появился в JavaSE в версии 1.4, в 2001 году. К этому моменту уже существовал Log4J, судя по всему, от него и отталкивались. Однако, как это очень часто бывало у Sun, перемудрили. Возможностей этот фреймворк давал меньше, чем Log4J, в использовании, по крайней мере на мой взгляд, был менее интуитивным. Тем не менее, у java.util.logging было большое преимущество – он был частью JavaSE. Не надо тащить с собой отдельную библиотеку, а иногда это критично.
Соответственно, в какой-то момент сложилась не очень приятная ситуация. В части приложений используется Log4J, в части – пакет java.util.logging. И все бы ничего, но возникает вопрос: а что делать разработчикам библиотек? Им тоже нужно использовать логирование. На какую из систем ориентироваться? API этих фреймворков различается, связывание происходит на этапе компиляции, просто так фреймворк логирования не заменить. Делать версию библиотеки под каждый? Это безумие.
Выход был найден достаточно простой. Раз у нас используются два разных фреймворка для одной цели – их надо унифицировать. Т.е. написать прослойку (фактически, адаптер), которая будет скрывать от разработчика, какой реально фреймворк он использует. Он будет звать прослойку, а она – конкретный фреймворк. Так появился Apache Commons Logging.
Apache Commons Logging
Фреймворк Apache Commons Logging предназначен для абстрагирования разработчика от конкретного фреймворка логирования. Он предоставляет некоторый унифицированный интерфейс, транслируя его вызовы в использование конкретных возможностей фреймворков. Ключевым тут является слово «унифицированный«. Оно означает минимальное доступное покрытие, т.е. отсутствие, например, специфических возможностей Log4J. А они бывают ОЧЕНЬ полезны.
Commons Logging абстрагирует следующие фреймворки:Log4J, java.util.logging, Avalon LogKit, Lumberjack (см.примечание 2). Кроме того, тот же унифицированный интерфейс реализован в самом фреймворке в двух вариантах – т.н. NOP 3 -вариант, и простейший вывод в System.err.
Появившись, Commons Logging стал спасением для разработчиков библиотек общего назначания. В результате этого он используется необычайно широко. Однако у него есть ряд существенных недостатков, с которыми приходилось мириться.
- Фреймворк является минимальным – не поддерживает очень полезных специфических возможностей абстрагируемых фреймворков.
- Фреймворк никак не занимается инициализацией и конфигурированием конкретных фреймворков логирования – это остается на самом разработчике. Но это все равно лучше, чем было до него – при смене фреймворка логирования нужно изменить только код инициализации.
- Самое неприятное – при некоторых условиях 4 у этого фреймворка есть проблемы с загрузчиком классов. В одном проекте нам пришлось отказаться от него и перейти на чистый Log4J именно по этой причине.
Если с первыми двумя неудобствами еще можно было как-то жить, то третье осложняло жизнь очень серьезно. В немалой степени из-за этого и появился следующий фреймворк – SLF4J.
Simple Logging Facade for Java
По своей сути SLF4J является тем же, чем и Commons Logging – абстрагирующим фреймворком логирования. Однако у него есть ряд важных отличий:
- SLF4J является более продвинутым, нежели Commons Logging – набор поддерживаемых им возможностей конечных фреймворков шире. Если где-то конкретный конечный фреймфорк не поддерживает каких-либо возможностей – делается их иммитация.
- SLF4J поддерживает (абстрагирует) большее количество фреймворков логирования, чем Commons Logging – это java.util.logging, Log4J, Commons Logging, Logback (он вообще является реализацией интерфейсов самого SLF4J). Есть две собственные реализации – NOP и Simple.
- SLF4J является приемником для java.util.logging, Log4J, Commons Logging – т.е. его можно подключить «под» эти фреймворки, так, что вывод через них будет перенаправляться в SLF4J. Единственное ограничение – невозможность работы в схеме Log4J >>SLF4J >>Log4J.
- Проблем с загрузчиком классов у него нет
Устроен SLF4J просто, в некоторой степени даже элегантно. Есть общая часть библиотеки, API. И есть несколько библиотек, каждая из которых реализует свою схему – SLF4J >> Log4J, SLF4J >> Commons Logging, SLF4J >> java.util.logging, SLF4J >> NOP, SLF4J >> Simple. Эти библиотеки подключаются простым помещением их в classpath. Сделано это следующим образом – каждая из дополнительных библиотек содержит класс с определенным именем (на самом деле классов несколько, но это неважно). Этот класс является, фактически, фабрикой для создания всех сущностей SLF4J на основе конкретного фреймворка. А следует из этого такой момент – дополнительные библиотеки можно подключать только по одной! Нет, можно и все, но задействована будет первая найденная в classpath-е.
В целом SLF4J является более удачным, нежели Commons Logging, потому в последнее время наблюдается тенденция перехода на него. Кстати, у этого фреймворка тот же автор, что и у Log4J.
При всех плюсах SLF4J один минус я все-таки знаю – он не дает изменять уровень детализации логирования для конкретного логгера во время исполнения (помните мечту?), хотя и Log4J и java.util.logging это поддерживают.
Ну и последний по порядку, но не по значению – Logback.
Logback
Logback концептуально является наследником Log4J. Что неудивительно, ибо автор у них один – вместе с SLF4J. И опять-таки неудивительно, что Logback при этом является реализацией интерфейсов SLF4J, т.е. максимально к нему приближен. Что немаловажно с точки зрения прежде всего производительности.
От Log4J Logback взял все хорошее, что там было. То есть – практически всё. По используемым понятиям они похожи до степени смешения. А когда читаешь документацию, понимаешь, что она местами вообще идентична. Однако в Logback добавлено несколько интересных возможностей, которые могут сильно облегчить жизнь. Как, например, зависимость уровня логирования от определенных параметров, что позволяет воспроизводить ошибки в режиме промышленной эксплуатации, выставляя уровень детального логирования не всему приложению, а только действиям, совершаемым указанным пользователем.
Подробно Logback я тоже рассматривать не буду – во-первых, потому что он сильно похож на Log4J, о котором мы будем говорить подробно, а во-вторых, потому что он еще, на мой взгляд, не достиг зрелости. Текущая его версия – 0.9.20. Однако по возможностям он весьма привлекателен, так что для текущих своих задач его непременно попробую, тем более что мы используем SLF4J, с которым Logback сочетается очень легко.
Краткое резюме
Подведем промежуточный итог. Хочу в очередной раз подчеркнуть – все нижесказанное является всего лишь моим мнением.
- Apache Log4J – хороший фреймворк для логирования, практически лишенный недостатков. Широко используется. Разработка находится, фактически, в замороженном 5 состоянии, производится только исправление ошибок.
- java.util.logging – фреймворк, являющийся частью JavaSE. По возможностям уступает Log4J. Тем не менее используется хотя бы потому, что всегда под рукой и не требует дополнительных библиотек.
- Apache Commons Logging – фреймворк, предназначенный для абстрагирования конкретного фреймворка («под» ним может работать как Log4J, так и java.util.logging, а также несколько других). Имеет определенные проблемы с загрузчиком классов, что в определенных ситуациях затрудняет его использование.
- SLF4J – еще один абстрагирующий фреймворк, существенно более удачный, чем Commons Logging. Может работать в двух ипостасях – как общий интерфейс к лежащим ниже фреймворкам и как приемник соответствующего типа для фреймворков, расположенных «над» ним.
- Logback – молодой, но весьма интересный фреймворк, выросший из Log4J. Взял от родителя все преимущества, плюс еще добавил своих. Возможно, в будущем станет даже более привлекательным, чем Log4J.
Теперь о том, что и когда использовать. Если вы пишете библиотеку, которая будет (или хотя бы может быть) использована сторонними разработчиками – имеет смысл использовать SLF4J. Этот фреймворк не будет вас стеснять, а другим даст свободу выбора. Commons Logging я бы не рекомендовал использовать вообще.
Если же вы разрабатываете собственное приложение, имеет смысл использовать Log4J. Он обладает большими возможностями, нежели java.util.logging, и даст вам больше пространства для маневра в том случае, если вы его же будете использовать «под» SLF4J. Например, в Log4J во время исполнения вы можете получить по имени логгер и поменять ему уровень (вот тут есть пример), а SLF4J в своем API такой возможности не имеет. Logback, на мой взгляд, использовать в промышленном режиме пока рано, хотя покрутить в руках, безусловно, стоит.
Есть, правда, и тут один нюанс. Мы у себя в собственном приложении, которое ни разу не библиотека, используем тем не менее SLF4J. Дело в том, что у нас задействована куча разных библиотек, которые, в свою очередь, используют кто во что горазд. И для того, чтобы весь этот зоопарк требуемых логгеров свести в одну точку, мы и используем SLF4J в режиме, так сказать, обратного мостика – «под» логгерами. А ниже него – Log4J, который мы уже конфигурируем напрямую, используя все его возможности.
Общая часть о различных фреймворках закончена, перейдем к конкретике.
Использование Log4J
Apache Log4J является весьма зрелым фреймворком, с устоявшимися принципами и понятиями. Поддерживает несколько способов конфигурации. Позволяет управлять своим поведением во время исполнения. Все это, а также многое другое, будет рассмотрено далее.
Принципы и понятия
В основе библиотеки Log4J лежит три понятия – логгер (logger), аппендер (appender) и компоновка (layout). К сожалению, нормальных эквивалентных русских терминов не существует, прижились заимствованные английские.
И еще к вопросу о терминологии – порции выводимых данных в Log4J называются сообщениями.
Логгер
Логгер представляет собой объект класса org.apache.log4j.Logger , который используется для вывода данных и управления уровнем (детализацией) вывода. В текущей версии – 1.2.16 – Log4J поддерживает следующие уровни вывода, в порядке возрастания:
Установка логгеру определенного уровня означает следующее – сообщения, выводимые с этим или более высоким уровнем, попадут в лог. Сообщения, выводимые с уровнем ниже установленного в лог не попадут. И в этом заключается вся прелесть – можно вставлять в программный код вывод информации на различных уровнях (об ошибках – на уровне ERROR, о нормальном ходе выполнения – на уровне INFO, отладочную – на уровне DEBUG), а потом гибко регулировать, что именно будет выводиться. Как именно регулировать – мы рассмотрим дальше.
Необходимо упомянуть еще о таком понятии как категория ( org.apache.log4j.Category ). Фактически это тот же логгер, я, честно сказать, не вижу разницы между ними, тем более что программно логгер наследует категорию. Рекомендуется использовать логгер, потому категорий я не касаюсь. Хотя в некоторых старых библиотеках типа Hibernate используются именно категории. Да и терминологически имя логгера чаще всего в документации называется категорией.
Другим важным свойством логгеров является то, что они организованы иерархично. Каждый логгер имеет имя, описывающее иерархию, к которой он принадлежит. Разделитель – точка. Принцип полностью аналогичен формированию имени пакета в Java.
Зачем это нужно. Дело в том, что установленный логгеру уровень вывода распространяется на все его дочерние логгеры, для которых явно не выставлен уровень. Проще это показать на примере.
Пусть у нас есть иерархия ru.skipy.logger.test. Это четыре логгера. Для начала назначим каждому свой уровень. Получается вот что:
Имя Назначенный уровень Эффективный уровень ru INFO INFO ru.skipy WARN WARN ru.skipy.logger DEBUG DEBUG ru.skipy.logger.test ERROR ERROR Теперь не будем назначать уровень логгерам ru.skipy и ru.skipy.logger.test. Тогда уровни будут такими:
Имя Назначенный уровень Эффективный уровень ru INFO INFO ru.skipy нет INFO ru.skipy.logger DEBUG DEBUG ru.skipy.logger.test нет DEBUG Возникает вопрос. А что будет, если не указать уровень для ru? Какой будет уровень?
Ответ простой. Дело в том, что помимо тех логгеров, которые создаются нами, есть еще один, корневой. У него нет имени, его можно получить с помощью специального метода. И именно этот логгер является родительским как для ru, так и для всех остальных на самом верхнем уровне. Именно его уровень они наследуют. Не установить этот уровень нельзя, это ошибка конфигурации.
Таким образом, реальная картинка на самом деле следующая:
Имя Назначенный уровень Эффективный уровень root INFO INFO ru нет INFO ru.skipy нет INFO ru.skipy.logger DEBUG DEBUG ru.skipy.logger.test нет DEBUG Такой подход дает большую гибкость – можно для всех на логгере root выставить требуемый уровень (чаще всего это ERROR), а для необходимых логгеров его менять, причем как в сторону понижения, так и в сторону повышения.
Переходим к следующему понятию, а именно –
Аппендер
Если логгер – это та точка, куда уходят сообщения в коде, то аппендер – это та точка, куда они приходят в конечном итоге. Например, файл. Или консоль. Хотя на самом деле список таких точек, поддерживаемых Log4J, намного шире:
- Консоль
- Файлы (несколько различных типов)
- JDBC
- Темы (topics) JMS
- NT Event Log
- SMTP
- Сокет
- Syslog
- Telnet
- Любой java.io.Writer или java.io.OutputStream
И это не говоря уже о том, что никто не мешает написать свой аппендер и благополучно его использовать. Да, все эти объекты реализуют интерфейс org.apache.log4j.Appender .
Логгеры связываются с аппендерами в соотношении «многие ко многим» – у одного логгера может быть несколько аппендеров, а к одному аппендеру может быть привязано несколько логгеров. Важно понимать, что аппендеры наследуются от родительских логгеров. Т.е., например, если к корневому (root) логгеру в конфигурации привязан аппендер A1, а к логгеру ru.skipy – A2, то вывод в логгер ru.skipy попадет в A2 и A1, а вывод в ru – только в A1.
И еще один момент, который обычно вызывает сложности. Уровень логирования наследуется (или устанавливается) независимо от аппендера. Иначе говоря, если на логгере root сконфигурирован вывод в A1 с уровнем ERROR, а на ru.skipy – в A2 с уровнем INFO, то вывод в ru.skipy с уровнем INFO попадет и в A2, и в A1, несмотря на то, что в конфигурации прямо рядом с A1 указан уровень ERROR. Такой поворот событий часто приводит в ступор – как же так, я же явно указываю для root уровень ERROR, почему же сюда сыпется всё, вплость до DEBUG. Как раз поэтому. Аппендер унаследовали, а уровень вывода переписали.
Существует возможность отказаться от наследования аппендеров. Для этого логгеру надо выставить свойство additivity в false, по умолчанию оно выставлено в true. Ну и, соответственно, всё вышесказанное в виде таблицы:
Имя логгера Назначенные аппендеры Значение additivity Эффективные аппендеры Комментарии root A1 A1 Родительских аппендеров нет, additivity значения не имеет ru A2,A3 true A1,A2,A3 Аппендеры родительского (корневого) логгера плюс собственные ru.skipy — true A1,A2,A3 Все аппендеры родительского логгера (включая унаследованные), собственных нет ru.skipy.logger A4 true A1,A2,A3,A4 Все аппендеры родительского логгера (включая унаследованные) плюс собственные info A5 false A5 Только собственные аппендеры – родительские не наследуются info.skipy — true A5 Только родительские аппендеры – от ближайшего родителя, собственных нет Эта таблица вместе с таблицей наследования уровней сильно облегчают понимание происходящего. Вывод идет во все эффективные аппендеры на эффективном уровне и вне зависимости от того, какой уровень сконфигурирован для родителя, к которому привязан соответствующий аппендер.
Поговорим теперь об имеющихся типах аппендеров. Всех мы касаться совершенно точно не будем, это выходит за рамки обзорной статьи. Желающих углубиться отсылаю к документации по интерфейсу: http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/Appender.html. Мы же будем говорить о тех типах, которые используются чаще всего. Это консоль и файлы.
Начнем с org.apache.log4j.ConsoleAppender , как с более простого. Этот аппендер используется для вывода данных в консоль (STDOUT). Это удобно при отладке, но практически ничего не дает в случае, когда надо диагностировать ошибку. Дело в том, что некоторые сервера приложений, например, вывод в консоль просто глушат – перехватывают и никуда не выпускают.
У консольного аппендера, как и у многих других (на самом деле – у всех, унаследованных от org.apache.log4j.WriterAppender), есть свойство, позволяющее указать ему кодировку, в которой выводить данные. На всякий случай напоминаю, что в Windows консоль имеет кодировку Cp866. Как это свойство выставляется, мы увидим в разделе Конфигурирование.
Теперь перейдем к основным аппендерам, использующимся наиболее широко – файловым. Их есть несколько типов:
- org.apache.log4j.FileAppender
- org.apache.log4j.RollingFileAppender
- org.apache.log4j.varia.ExternallyRolledFileAppender
- org.apache.log4j.DailyRollingFileAppender
org.apache.log4j.FileAppender
Начнем опять с самого простого – org.apache.log4j.FileAppender . Как нетрудно доогадаться, этот аппендер добавляет данные в файл. До бесконечности. И в этом его существенный недостаток – файл размером в 500Мб просмотривать весьма неудобно. Да и с записью бывают проблемы. Потому этот аппендер сам по себе практически не используется. Он является базой для остальных, предоставляя общие средства работы с файлами. Поддерживает этот аппендер следующие свойства: append (дописывать существующий файл или каждый раз начинать заново), bufferedIO (буферизовать ли вывод в файл), file (имя файла). Ну и от org.apache.log4j.WriterAppender унаследовано свойство encoding.
org.apache.log4j.RollingFileAppender
Гораздо интереснее org.apache.log4j.RollingFileAppender . Этот аппендер позволяет ротировать файл по достижении определенного размера. «Ротировать» означает, что текущему файлу приписывается расширение «.0» и открывается следующий. По достижении им максимального размера – первому вместо расширения «.0» выставляется «.1», текущему – «.0», открывается следующий. И так далее. Максимальный размер файла и максимальный индекс, устанавливаемый сохраняемым предыдущим файлам, задаются свойствами maximumFileSize и maxBackupIndex соответственно. Если индекс должен быть превышен – файл не переименовывается, а удаляется. Таким образом мы всегда имеем не больше определенного количества файлов, каждый из которых не больше определенного объема. Гораздо более предсказуемая ситуация, чем с обычным FileAppender-ом. Собственно, этот тип аппендеров, наверное, самый используемый.
org.apache.log4j.varia.ExternallyRolledFileAppender
Дальше идет org.apache.log4j.varia.ExternallyRolledFileAppender . Любопытный аппендер, я бы сказал – вещь в себе. Он унаследован от org.apache.log4j.RollingFileAppender-а, соответственно, ведет себя так же и имеет те же свойства. Однако вдобавок к этому он еще слушает указанный ему порт. Если открыть соединение на этот порт и послать строку «RollOver» (через DataOutputStream.writeUTF(java.lang.String) ) – аппендер выполняет внеочередную смену индексов. Мне сложно представить, зачем такое нужно, хотя может пригодиться.
org.apache.log4j.DailyRollingFileAppender
Следующий! org.apache.log4j.DailyRollingFileAppender . Очень полезный и функциональный аппендер. В отличии от org.apache.log4j.RollingFileAppender-а, ротирующего файл по достижении определенного размера, org.apache.log4j.DailyRollingFileAppender ротирует файл с определенной частотой. Она зависит от шаблона, указанного в конфигурации:
- ‘.’yyyy-MM – файл ротируется раз в месяц
- ‘.’yyyy-ww – файл ротируется раз в неделю
- ‘.’yyyy-MM-dd – файл ротируется раз в день
- ‘.’yyyy-MM-dd-a – файл ротируется раз в полдня
- ‘.’yyyy-MM-dd-HH – файл ротируется раз в час
- ‘.’yyyy-MM-dd-HH-mm – файл ротируется раз в минуту
При ротации к имени файла в конце приписываются текущие дата и время, отформатированные согласно указанному шаблону (с помощью класса java.text.SimpleDateFormat ). В кавычках в начале шаблона указан символ, который будет использоваться как разделитель между значением даты/времени и именем файла. В принципе этот символ может быть практически любым, кроме «:» – он интерпретируется в имени файла как указатель имени сетевого протокола (всё, что стоит до «:»).
Этот аппендер может быть весьма удобен в случае, когда у вас организована автоматическая архивация лога. Кроме того, наличие в имени файла временной метки делает его по определению уникальным – лог не потеряется, как это может произойти с обычным ротирующим аппендером.
Как конфигурируются все эти аппендеры, мы увидим в соответствующем разделе. А пока переходим к третьему базовому понятию.
Компоновка
Мы уже знаем, что нужно использовать, чтобы вывести данные – логгер. Правда, пока не знаем, как – но это ненадолго. 🙂 Мы знаем, что нужно использовать для конфигурирования точки назначения – аппендер. Однако мы еще не знаем, как сконфигурировать формат вывода данных. Пришла пора узнать и это.
Для конфигурирования формата вывода используются наследники класса org.apache.log4j.Layout :
- org.apache.log4j.SimpleLayout
- org.apache.log4j.HTMLLayout
- org.apache.log4j.xml.XMLLayout
- org.apache.log4j.TTCCLayout
- org.apache.log4j.PatternLayout / org.apache.log4j.EnhancedPatternLayout
У каждого из них свое предназначение и свои возможности.
org.apache.log4j.SimpleLayout
Наиболее простой вариант. На выходе дает уровень вывода и, собственно, сообщение. T.e. следующий код –
logger.info("Some message");
– на выходе даст вот так отформатированную строку:
INFO - Some message
В принципе, для какого-то простейшего случая такая компоновка может и пригодиться. Однако необходимо заметить, что вывод исключений в лог при использовании данной компоновки невозможен.
org.apache.log4j.HTMLLayout
Более интересный вариант. Форматирует сообщения в виде HTML-таблицы. У этого компоновщика есть два свойства – Title и LocationInfo, задающие заголовок HTML-документа и режим вывода информации о точке, где сгенерировано сообщение (имя файла и номер строки в нем) соответственно. По умолчанию LocationInfo имеет значение false, т.к. генерация информации о точке возникновения сообщения – крайне затратная процедура.
Есть один момент, который необходимо принимать внимание при использовании этого компоновщика. Формат HTML требует корректного закрытия документа. А при генерации вывода, естественно, ни о каком закрытии речи не идет – мы непрерывно добавляем сообщения, т.е. строки в таблицу. Так вот, для того, чтобы получить корректный документ, необходимо закрыть компоновщик в конце работы, обычно при выходе из приложения. Делается это при помощи следующего вызова статического метода:
org.apache.log4j.LogManager.shutdown();Фактически, это закрытие всей системы логирования – сброс всех кешированных данных, закрытие всех форматов и т.п.
Результат работы этого компоновщика на примере, описанном выше, можно увидеть в этом документе. Вызов логгера производится в методе main класса ru.skipy.logging.tests.Log4JTest , в строке 19.
Исключения данный компоновщик поддерживает. Необходимо также помнить, что при его использовании кодировка аппендеру должна быть выставлена в UTF-8 или UTF-16 , в противном случае данные при выводе могут быть повреждены. Хотя сам компоновщик кодировку в генерируемый HTML не добавляет.
org.apache.log4j.xml.XMLLayout
Этот компоновщик формирует сообщения в виде XML. В противовес HTMLLayout он не генерирует корректного – well-formed – документа. Результаты его работы должны быть вставлены в определенное XML-обрамление – только тогда получится корректный документ. Подробнее можно посмотреть вот тут: http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/xml/XMLLayout.html.
Ну и соответственно, результатом работы на примере, упомянутом выше, будет вот такой фрагмент xml-документа:
log4j:event logger="ru.skipy.logging.tests.Log4JTest" timestamp="1274084709955" level="INFO" thread="Main Thread"> log4j:message>![CDATA[Some message]]>/log4j:message> log4j:locationInfo class="ru.skipy.logging.tests.Log4JTest" method="main" file="Log4JTest.java" line="19"/> /log4j:event>
Всё, что сказано о свойстве LocationInfo применительно к HTMLLayout, справедливо и тут. Исключения данный компоновщик также поддерживает. И точно так же аппендеру должна быть выставлена кодировка UTF-8 или UTF-16 .
org.apache.log4j.TTCCLayout
TTCC – сокращение от Time-Thread-Category-Context. Означает оно, что помимо, собственно, сообщения, в лог выводится информация о времени, потоке, категории (имени логгера) и вложенном диагностическом контексте (о них мы поговорим ниже). У компоновщика есть булевские свойства CategoryPrefixing, ContextPrinting и ThreadPrinting, указывающие, выводить или нет категорию, контекст и имя потока, соответственно. По умолчанию все три свойства выставлены в true.
Еще одно свойство – DateFormat. Оно позволяет указать, в каком варианте будет выводиться время. Имеется пять предустановленных форматов (шаблоны указаны применительно к java.text.SimpleDateFormat ):
Имя формата Значение NULL Значение не выводится RELATIVE Число – количество миллисекунд с момента инициализации Log4J ABSOLUTE Время в формате » HH:mm:ss,SSS « DATE Дата и время в формате » dd MMM yyyy HH:mm:ss,SSS « ISO8601 Дата и время в формате » yyyy-MM-dd HH:mm:ss,SSS « Если значение не соответствует ни одному из предустановленных – это должен быть шаблон в формате, поддерживаемом java.text.SimpleDateFormat .
В следующей таблице содержатся результаты вывода в лог сообщения, приведенного выше, в зависимости от указанного формата даты:
Формат даты Сообщение в логе NULL [Main Thread] INFO ru.skipy.logging.tests.Log4JTest — Some message RELATIVE 15 [Main Thread] INFO ru.skipy.logging.tests.Log4JTest — Some message ABSOLUTE 13:26:34,804 [Main Thread] INFO ru.skipy.logging.tests.Log4JTest — Some message DATE 17 май 2010 13:26:34,804 [Main Thread] INFO ru.skipy.logging.tests.Log4JTest — Some message ISO8601 2010-05-17 13:26:34,804 [Main Thread] INFO ru.skipy.logging.tests.Log4JTest — Some message dd.MM.yyyy HH:mm:ss.SSS 17.05.2010 13:26:34.804 [Main Thread] INFO ru.skipy.logging.tests.Log4JTest — Some message Компоновщик TTCCLayout поддерживает вывод исключений. При программном использовании необходимо помнить, что этот компоновщик НЕ потоко-независимый (not thread-safe), так что необходимо создавать по экземпляру на каждый аппендер, к которому он привязывается.
org.apache.log4j.PatternLayout / org.apache.log4j.EnhancedPatternLayout
Наконец мы добрались до самого мощного и наиболее часто используемого компоновщика – PatternLayout. Он использует шаблонную строку для форматирования выводимого сообщения. Формат чем-то напоминает printf – тот же знак ‘%’ , после которого (возможно) идет модификатор формата и дальше символ, обозначающий тип выводимых данных. Кроме таких служебных комбинаций в строку шаблона можно вставлять любые символы, что позволяет еще более гибко конфигурировать лог.
На самом деле, как вы можете заметить, в заголовке упомянут еще и такой компоновщик, как org.apache.log4j.EnhancedPatternLayout . Этот класс появился только в версии 1.2.16. В документации к нему написано, что он является улучшенной версией org.apache.log4j.PatternLayout и должен использоваться вместо старого него. Я не заметил каких-то особых улучшений, хотя изменения, безусловно, есть. Далее я буду указывать отличия там, где они появятся.
В следующей таблице приведены опции, обозначающие типы выводимых данных. Обратите внимание, что они чувствительны к регистру – ‘c’ означает совсем не то, что ‘C’.
После символа категории в фигурных скобках может следовать указание – сколько частей имени категории выводить. Они отсчитываются с конца, что логично – это позволяет отсечь длинное имя пакета. Т.е., например, при имени категории ru.skipy.logging.tests.Log4JTest комбинация %c приведет к выводу в лог logging.tests.Log4JTest (три части имени с конца). Если такого указания нет – имя выводится целиком.
У org.apache.log4j.EnhancedPatternLayout есть еще несколько вариантов сокращения имени. Отрицательное значение в скобках означает «убрать указанное количество частей сначала». Т.е. при имени категории ru.skipy.logging.tests.Log4JTest комбинация %c приведет к выводу в лог Log4JTest – три первых части убраны. Если убрать надо большее количество частей, чем присутствует – будет выведено все имя целиком.
Не путайте это имя с именем категории. В разделе Использование в программном коде мы увидим, что это две большие разницы. Имя категории может не совпадать с именем класса.
После имени класса также может идти указание на то, сколько частей имени выводить – полностью аналогично опции ‘%c’ .
Важно! Генерация имени класса – достаточно медленная процедура. Стоит ее избегать при наличии такой возможности. И уж точно не стоит оставлять эту опцию в настройках в режиме промышленной эксплуатации.
Выводит в лог текущие дату и/или время. В фигурных скобках после данной опции указывается формат даты – либо шаблон java.text.SimpleDateFormat , либо один из предустановленных – DATE , ABSOLUTE или ISO8601 . Сравните этот набор с таблицей выше – поддерживаются не все форматы, перечисленные для TTCCLayout. Если указания на шаблон нет, используется формат ISO8601 .
Документация рекомендует использовать предопределенные форматы вместо собственных шаблонов – под них разработаны специальные классы для более оптимального форматирования, чем это делает java.text.SimpleDateFormat .
Не путайте с именем класса. В данном случае в лог выведется именно имя файла, в общем случае не совпадающее с именем класса, например, для любых внутренних классов.
Содержит имя класса, имя метода, имя файла и строку, в которой было сгенерировано сообщение. Т.е. для нашего примера выше (напомню, что вызов логгера производится в методе main класса ru.skipy.logging.tests.Log4JTest , в строке 19), в лог будет выведена строка ru.skipy.logging.tests.Log4JTest.main(Log4JTest.java:19) .
Имеется в виду номер строки в файле. В принципе информация полезная, хотя часто можно обойтись и без нее.
Переводит в логе строку. Это необходимо, иначе все сообщения будут писаться в одну строку.
Для чего нужна такая опция – конец строки, вообще-то, платформозависимый. Под Windows это ‘\r\n’ (CRLF), под *NIX – ‘\n’ (LF), на Mac-ах до недавнего времени был ‘\r’ (CR), в MacOS X, возможно, стал как в *NIX. И стандартная для одной системы комбинация может быть неправильно интерпретирована в другой.
Выводит связанный с текущим потоком ассоциативный диагностический контекст. После опции в фигурных скобках должно идти имя ключа, по которому выбирается значение из контекста: %X – вывод из контекста имени пользователя, если оно там есть.
Эта опция специфична только для org.apache.log4j.EnhancedPatternLayout , у org.apache.log4j.PatternLayout ее нет. Выводит свойство по имени, указанному в фигурных скобках после опции. Если имя не указано – выводятся все свойства.
С учетом баланса между требованиями производительности и объемом информации, которого достаточно для анализа логов, в промышленном режиме рекомендовано использование следующих опций: %c, %d, %m, %n, %p, %t, %x, %X, %throwable, %% . Остальные – %C, %F, %l, %L, %M – способны вызвать сильное падение производительности.
С опциями закончили. Но если вы думаете, что возможности по настройке компоновщика на этом заканчиваются – вы в иллюзии. Все только начинается. 🙂
Данный компоновщик поддерживает, кроме всего прочего, позиционное форматирование. Означает оно, что под каждую опцию можно выделить некоторое место – задать минимальный и максимальный размер значения, а также выравнивание, если значение меньше минимальной выделенной области. Модификаторы форматирования задаются между символом ‘%’ и опцией. На примере опции %c рассмотрим действие модификаторов:
Модификатор Выравнивание Минимальная ширина Максимальная ширина Действие %10с вправо 10 нет Отводит минимум 10 символов под имя категории, если длина значения меньше – выравнивает его по правому краю поля %-10с влево 10 нет Отводит минимум 10 символов под имя категории, если длина значения меньше – выравнивает его по левому краю поля %.20с нет нет 20 Отводит максимум 20 символов под имя категории, если длина значения больше – обрезает с начала, оставляя указаное количество символов. Поскольку длина значения не может быть меньше предопределенной, о выравнивании говорить не приходится. %10.20с вправо 10 20 Отводит минимум 10 и максимум 20 символов под имя категории, если длина значения меньше – выравнивает его по правому краю поля, если больше – обрезает с начала, оставляя 20 символов. %-10.20c влево 10 20 Отводит минимум 10 и максимум 20 символов под имя категории, если длина значения меньше – выравнивает его по левому краю поля, если больше – обрезает с начала, оставляя 20 символов. Думаю, суть ясна. Теперь – для чего это нужно. Ну, ограничивать размер выводимой информации сверху – в приниципе правильно. Сообщение размером в 10000 символов не несет никакой практической ценности. Только загромождает лог, искать действительно важную информацию становится труднее. А вот зачем ограничивать размер снизу?
А это тоже просто. Представьте себе, что вы выводите в лог, скажем, дату, имя потока, приоритет, категорию и сообщение. Сравните два следующих фрагмента:
11:31:32,342 Thread-1 ERROR ru.skipy.tests.audit.LoadTest - Check in 344ms: GlobalID=2 11:31:32,358 Thread-17 WARN ru.skipy.tests.ServiceLoadTest - Check in 156ms: GlobalID=8 11:31:32,378 Thread-2 INFO ru.skipy.tests.trace.ServiceLoadTrace - Check in 328ms: GlobalID=3 11:31:35,358 Thread-44 DEBUG ru.skipy.tests.parallel.ext.ServiceParallelLoadTest - Check in 250ms: GlobalID=5 11:31:36,637 Thread-503 INFO ru.skipy.tests.ServiceLoadTest - Check in 219ms: GlobalID=6 11:31:37,846 Thread-59 INFO ru.skipy.tests.extract.Extractor - Check in 94ms: GlobalID=10 11:31:39,072 Thread-86 DEBUG ru.skipy.tests.ServiceLoadTest - Check in 188ms: GlobalID=7 11:31:41,309 Thread-10 INFO ru.skipy.tests.back.BackLoaderInfo - Check in 47ms: GlobalID=11
11:31:32,342 Thread-1 ERROR ru.skipy.tests.audit.LoadTest - Check in 344ms: GlobalID=2 11:31:32,358 Thread-17 WARN ru.skipy.tests.ServiceLoadTest - Check in 156ms: GlobalID=8 11:31:32,378 Thread-2 INFO ipy.tests.trace.ServiceLoadTrace - Check in 328ms: GlobalID=3 11:31:35,358 Thread-44 DEBUG llel.ext.ServiceParallelLoadTest - Check in 250ms: GlobalID=5 11:31:36,637 Thread-503 INFO ru.skipy.tests.ServiceLoadTest - Check in 219ms: GlobalID=6 11:31:37,846 Thread-59 INFO ru.skipy.tests.extract.Extractor - Check in 94ms: GlobalID=10 11:31:39,072 Thread-86 DEBUG ru.skipy.tests.ServiceLoadTest - Check in 188ms: GlobalID=7 11:31:41,309 Thread-10 INFO .skipy.tests.back.BackLoaderInfo - Check in 47ms: GlobalID=11
Вопросы. В каком из двух вариантов сообщения читаются проще? Насколько быстро вы можете найти в строке начало сообщения в первом из двух вариантов? А во втором? Как быстро вы можете увидеть, какой категории сообщение?
На мой взгляд, разница видна невооруженным глазом. Второй вариант существенно удобнее читать. А отличается он от первого только тем, что для имени потока, приоритета и категории установлены минимальные ширины – 10, 5 и 32 символа соответственно. Максимальные установлены так же, в результате чего длинные категории не вылезают за отведенные им пределы, и сообщения, соответственно, все начинаются с одной и той же позиции. Более того, даже этот вариант можно несколько улучшшить. Мы знаем, что категория всегда начинается с ru.skipy.tests, и видеть в логе эту часть нам совершенно необязательно. Т.е. ее можно убрать (с помощью %c ), тогда лог будет выглядеть еще красивее:
11:31:32,342 Thread-1 ERROR audit.LoadTest - Check in 344ms: GlobalID=2 11:31:32,358 Thread-17 WARN ServiceLoadTest - Check in 156ms: GlobalID=8 11:31:32,378 Thread-2 INFO trace.ServiceLoadTrace - Check in 328ms: GlobalID=3 11:31:35,358 Thread-44 DEBUG ext.ServiceParallelLoadTest - Check in 250ms: GlobalID=5 11:31:36,637 Thread-503 INFO ServiceLoadTest - Check in 219ms: GlobalID=6 11:31:37,846 Thread-59 INFO extract.Extractor - Check in 94ms: GlobalID=10 11:31:39,072 Thread-86 DEBUG ServiceLoadTest - Check in 188ms: GlobalID=7 11:31:41,309 Thread-10 INFO back.BackLoaderInfo - Check in 47ms: GlobalID=11
Теперь и категория читается легко.
Ну и последнее – пример шаблона, от которого я обычно отталкиваюсь в работе:
%d [%-5p][%-16.16t][%32.32c] - %m%n
- Дата в формате ISO8601 . Когда логи большие, только времени будет недостаточно, нужна и дата. У формата DATE используется символьное имя месяца, потому ширина получается переменной.
- Приоритет – минимально 5 символов (а больше и не бывает в Log4J), выравнивание влево.
- Имя потока – 16 символов, выравнивание влево.
- Категория – 32 символа, выравнивание вправо. В принципе, можно обрезать начальные части имени, но тогда надо быть уверенным, что в конкретный аппендер будут идти логи только от собственного кода, иначе есть риск не увидеть разницы между ru.skipy.SQL и org.hibernate.SQL .
- Сообщение, после которого идет символ окончания строки.
Все части лога, кроме даты и сообщения, заключены в квадратные скобки. Это улучшает читаемость – визуально подчеркивает колонки. Да, я забыл упомянуть раньше – в шаблон можно включать любые символы помимо, собственно, описателей элементов лога. При необходимости в шаблон можно добавить и вывод диагностических контекстов (MDC и NDC).
И последняя часть в разделе о концепциях Log4J –
Диагностические контексты
Понятия диагностических контекстов я, честно сказать, до Log4J не встречал. Используются они редко, а зря, на мой взгляд. Ибо иногда крайне полезная вещь. Итак, что это такое и для чего это нужно.
Представьте себе веб-приложение. Множество пользователей, множество запросов. Информация идет в лог. И вот, у одного пользователя возникают проблемы. Система ведет себя странно. У других – все в порядке. Надо разобраться, что делает не так этот пользователь. Вопрос. Как отследить в логах именно его действия?
Log4J много чего умеет выводить самостоятельно – набор опций в том же PatternLayout достаточно велик – но он все-таки не всесилен. И всегда будет дополнительная, диагностическая информация, которую придется выводить нам самостоятельно. На первый взгляд сложностей это не вызывает. Ну получить имя пользователя, ну вставить в сообщение – что сложного?
А сложность тут в том, что для четкой идентификации имя пользователя надо добавлять в КАЖДОЕ сообщение. Т.е. его либо надо будет получать во всех точках, где ведется лог, что означает, что весь код должен знать о том, что он выполняется под каким-то пользователем, – бессмысленное знание для большей части кода, – либо протаскивать его туда как параметр, что означает ровно то же самое.
Да и это не даст нужного результата. Ну да, в свои сообщения вы имя пользователя добавите. А в сообщения Hibernate? А в сообщения остальных девяноста девяти библиотек?
Можно, конечно, отслеживать, в каком потоке начинается запрос, а потом ориентироваться по имени потока. Беда только в том, что потоки сервер переиспользует. И потеряться, где закончился прошлый запрос, и начался следующий, от другого пользователя, легче легкого. Поверьте на слово.
И это всего лишь один пример, а их намного больше. Необходимость во включении в лог дополнительной информации возникает довольно часто. А протаскивать эту информацию до точки генерации сообщения либо сложно (часто), либо неправильно (практически всегда), либо вообще нереально, в случаях с любыми библиотеками.
Вот тут-то как раз и появляется такое понятие как диагностический контекст. Как вы понимаете из названия, он представляет собой некий набор информации – контекст, – предназначенный для диагностики чего-либо.
Диагностических контекстов в Log4J два разных типа – вложенные (Nested diagnostic context, NDC) и ассоциативные (Mapped diagnostic context, MDC). Разница между двумя этими контекстами во внутренней организации. Вложенный представляет собой стек. Ассоциативный – ассоциативный массив (map). Подробнее они будут рассмотренны в разделе об использовании в программном коде, здесь описаны только общие принципы.
Диагностический контекст привязывается к потоку, с помощью java.lang.ThreadLocal . Это обеспечивает его доступность в любой точке, где выводится в лог сообщение. Поскольку добавлением контекста в лог занимается Log4J, а не мы, – это возможно даже в тех точках, где мы создание сообщений не контролируем. Надо только добавить соответствующие опции в шаблон в PatternLayout. Также вложенный контекст выводится еще и TTCCLayout-ом.
Вот мы и добрались до практики. Начнем с конфигурирования.
Конфигурирование
Конфигурирование Log4J осуществляется двумя способами – через файл свойств и через xml-файл. Принято считать эти два способа равнозначными. У меня по этому поводу нет четкого мнения, сам я досконально этот вопрос не исследовал, а документация по самому Log4J местами противоречива (например, в описании класса org.apache.log4j.PropertyConfigurator сказано, что обработчики ошибок он не поддерживает, а в описании метода doConfigure этого же класса приведен формат конфигурации обработчиков ошибок). В любом случае за более чем 5 лет использования Log4J я ни разу не сталкивался с разницей в возможностях конфигурации. Потому для наших целей будем считать эти способы равноценными и выбирать, что именно использовать, исходя из собственных предпочтений.
Я лично предпочитаю использовать xml-формат. Во-первых, он, на мой взгляд, проще для понимания, прежде всего за счет структуры. Во-вторых, в отличие от файла свойств, тут все-таки есть DTD 6 , т.е. – формат более строгий. Все примеры я, естественно, буду давать в обоих вариантах.
Как нетрудно догадаться, конфигурационные файлы называются log4j.properties и log4j.xml. При инициализации Log4J они ищутся в classpath , сначала xml-файл, потом properties-файл. Так что при наличии обоих рабочим будет именно xml.
Итак, простейшие конфигурации. В XML:
?xml version="1.0" encoding="UTF-8" ?> !DOCTYPE log4j:configuration SYSTEM "log4j.dtd"> log4j:configuration debug="false" xmlns:log4j="http://jakarta.apache.org/log4j/"> appender name="ConsoleAppender" class="org.apache.log4j.ConsoleAppender"> param name="Encoding" value="Cp866"/> layout class="org.apache.log4j.PatternLayout"> param name="ConversionPattern" value="%d [%-5p][%-16.16t][%32.32c] - %m%n" /> /layout> /appender> root> priority value="ERROR"/> appender-ref ref="ConsoleAppender" /> /root> /log4j:configuration>
И в виде свойств:
log4j.debug = false log4j.rootLogger = ERROR, ConsoleAppender log4j.appender.ConsoleAppender = org.apache.log4j.ConsoleAppender log4j.appender.ConsoleAppender.encoding = Cp866 log4j.appender.ConsoleAppender.layout = org.apache.log4j.PatternLayout log4j.appender.ConsoleAppender.layout.ConversionPattern = %d [%-5p][%-16.16t][%32.32c] - %m%n
Что тут сделано:
- Создан аппендер с именем ConsoleAppender и кодировкой Cp866
- У созданного аппендера установлен компоновщик PatternLayout с шаблоном %d [%-5p][%-16.16t][%32.32c] — %m%n
- Сконфигурирован корневой логгер, использующий созданный аппендер и имеющий уровень ERROR .
- В случае файла свойств порядок указания свойств не важен – все равно они будут загружены в виде java.util.Properties , а там порядок не сохраняется
- В случае XML-конфигурации порядок важен – он диктуется DTD.
- В данном примере в явном виде указано, что внутренний лог Log4J отключен – свойство log4j.debug и атрибут debug у корневого элемента в XML имеют значение false . Иногда необходимо посмотреть на работу самого Log4J, в этом случае данное свойство просто выставляется в true.
- Формат имен свойств следующий: базовая часть log4j.
. , дальше могут следовать имена свойств, например, layout , дальше – имя свойства внутри свойства, например, ConversionPattern . Таким образом создается древесная структура. XML в этом отношении более естественнен – он изначально имеет древесную структуру и вложенность свойств в нем видна с первого взгляда. - Как уже упоминалось, логгеры с аппендерами связаны отношением «многие ко многим», соответственно, у логгера может быть указано несколько аппендеров. В XML просто повторяется тег appender-ref с соответствующим именем аппендера (добавляем FileAppender):
root> priority value="ERROR"/> appender-ref ref="ConsoleAppender" /> appender-ref ref="FileAppender" /> /root>
В свойствах – аппендер указывается через запятую:
log4j.rootLogger = ERROR, ConsoleAppender, FileAppender
Теперь сконфигурируем что-нибудь посложнее. Консоль уберем, добавим вывод в несколько файлов, для разных категорий и с разными уровнями.
?xml version="1.0" encoding="UTF-8" ?> !DOCTYPE log4j:configuration SYSTEM "log4j.dtd"> log4j:configuration debug="false" xmlns:log4j="http://jakarta.apache.org/log4j/"> appender name="bulk" class="org.apache.log4j.DailyRollingFileAppender"> param name="File" value="bulk.log"/> param name="Append" value="true"/> param name="DatePattern" value="'.'yyyy-MM-dd'.log'"/> param name="Encoding" value="UTF-8"/> layout class="org.apache.log4j.EnhancedPatternLayout"> param name="ConversionPattern" value="%d [%-5p][%-16.16t][%30c] - %m%n"/> /layout> /appender> appender name="application" class="org.apache.log4j.RollingFileAppender"> param name="File" value="application.log"/> param name="MaxFileSize" value="100MB"/> param name="MaxBackupIndex" value="10"/> param name="Encoding" value="UTF-8"/> layout class="org.apache.log4j.EnhancedPatternLayout"> param name="ConversionPattern" value="%d [%-5p][%-16.16t][%30c] - %m%n"/> /layout> /appender> appender name="orm" class="org.apache.log4j.DailyRollingFileAppender"> param name="File" value="orm.log"/> param name="DatePattern" value="'.'yyyy-MM-dd'.log'"/> param name="Encoding" value="UTF-8"/> layout class="org.apache.log4j.TTCCLayout"> param name="DateFormat" value="ABSOLUTE"/> param name="ContextPrinting" value="false"/> /layout> /appender> logger name="ru.skipy"> level value="INFO"/> appender-ref ref="application"/> /logger> logger name="org.hibernate" additivity="false"> level value="WARN"/> appender-ref ref="orm"/> /logger> root> priority value="WARN"/> appender-ref ref="bulk"/> /root> /log4j:configuration>
log4j.debug=false log4j.rootLogger=WARN, bulk log4j.appender.bulk=org.apache.log4j.DailyRollingFileAppender log4j.appender.bulk.file=bulk.log log4j.appender.bulk.append=true log4j.appender.bulk.datePattern='.'yyyy-MM-dd'.log' log4j.appender.bulk.layout=org.apache.log4j.EnhancedPatternLayout log4j.appender.bulk.layout.conversionPattern=%d [%-5p][%-16.16t][%30c] - %m%n log4j.appender.application=org.apache.log4j.RollingFileAppender log4j.appender.application.file=application.log log4j.appender.application.file.MaxBackupIndex=10 log4j.appender.application.file.MaxFileSize=100MB log4j.appender.application.layout=org.apache.log4j.EnhancedPatternLayout log4j.appender.application.layout.conversionPattern=%d [%-5p][%-16.16t][%20c] - %m%n log4j.appender.orm=org.apache.log4j.DailyRollingFileAppender log4j.appender.orm.file=orm.log log4j.appender.orm.datePattern='.'yyyy-MM-dd'.log' log4j.appender.orm.layout=org.apache.log4j.TTCCLayout log4j.appender.orm.layout.dateFormat=ABSOLUTE log4j.appender.orm.layout.contextPrinting=false log4j.logger.ru.skipy=INFO, application log4j.logger.org.hibernate=WARN, orm log4j.additivity.org.hibernate=false
Что тут сделано:
- Создано три аппендера – bulk, application и orm. Они выводят сообщения в разные файлы, в разных форматах. Например, у application при выводе обрезаются два начальных элемента имени категории.
- Сконфигурированы логгеры – ru.skipy выводится в application, org.hibernate – в orm. У org.hibernate флаг additivity установлен в false .
- Сконфигурирован корневой логгер, использующий аппендер bulk и имеющий уровень WARN .
- Обратите внимание, как выставляется флаг additivity в случае файла свойств и в XML. Это как раз пример той неочевидности, из-за которой я предпочитаю XML – там принадлежность этого свойства не вызывает сомнений.
Перевожу данную конфигурацию на русский язык.
- Все сообщения из своего приложения – имя категории начинается на ru.skipy – я хочу выводить в файл application.log. Именно поэтому в аппендере я могу обрезать первые две части имени категории – они всегда будут ru.skipy, и мне незачем загромождать лог ненужной информацией. Раз в сутки я хочу создавать новый файл, для удобства анализа и архивации.
- Все сообщения от всего исполняемого кода я хочу выводить в bulk.log. Этот файл я буду обрезать по размеру. Сюда же будут попадать и сообщения от моего кода, т.к. аппендер унаследован от корня. Это, в общем-то, логично – помимо анализа работы собственно моего кода мне необходимо смотреть на все приложение в целом. Уровень всех сообщений я выставляю в WARN при конфигурации корневого логгера, он будет действовать на все сообщения, кроме моих (у них используется сконфигурированный для ru.skipy уровень INFO ).
- Временами мне необходимо смотреть, что происходит при работе с базой – какие запросы генерируются, какие результаты возвращаются. При этом будет использоваться уровень DEBUG , т.е. информации будет очень много. Чтобы она не загромождала основной лог, я выставляю флаг additivity в false . По умолчанию уровень выставлен в WARN , что минимизирует временные потери на лог.
Продолжать приводить примеры можно долго, но смысла нет. Общий принцип организации лога следующий. Путем рассуждений, подобных только что приведенным, решите:
- какую информацию вы хотите видеть
- как вы хотите группировать или разделять эту информацию
- в каком формате вам нужна информация
- как вы хотите архивировать информацию за прошлые периоды, и хотите ли вообще, какой максимальный объем логов вы готовы хранить единовременно
После того, как вы определитесь со всеми этими вопросами – можете писать конфигурацию.
И еще один вопрос, который иногда вполне закономерно возникает. Можно ли сконфигурировать вывод так, чтобы в один аппендер сообщения от определенного логгера выводились на одном уровне, а в другой на другом?
Можно. Вариантов два. Первый – параметр аппендера Threshold, который содержит минимальный уровень сообщений для этого аппендера. Конфигурируется он соответственно:
appender name="bulk" class="org.apache.log4j.DailyRollingFileAppender"> param name="Threshold" value="WARN"/> /appender>
log4j.appender.bulk.threshold=WARN
И второй вариант – использование фильтров. У аппендера можно создать фильтр (на самом деле, любую цепочку), который, в числе прочего, может фильтровать по уровню лога ( org.apache.log4j.varia.LevelRangeFilter ). Подробно останавливаться на фильтрах не буду, желающие могут посмотреть описание и примеры использования, например, тут. Пример конфигурирования:
appender name="bulk" class="org.apache.log4j.DailyRollingFileAppender"> filter class="org.apache.log4j.varia.LevelRangeFilter"> param name="LevelMin" value="warn"/> param name="LevelMax" value="fatal"/> param name="AcceptOnMatch" value="true"/> /filter> /appender>
log4j.appender.bulk.filter.a=org.apache.log4j.varia.LevelRangeFilter log4j.appender.bulk.filter.a.LevelMin=WARN log4j.appender.bulk.filter.a.LevelMax=FATAL log4j.appender.bulk.filter.a.AcceptOnMatch=TRUE
Порядок фильтров для XML-конфигурации определяется порядком их описания (согласно DTD фильтры конфигурируются после layout-ов). В случае properties-конфигурации фильтры сортируются по имени.
Пожалуй, о конфигурации сказано достаточно. Основные аппендеры и компоновщики я описал, примеры привел. Соответственно, можно перейти к следующей части.
Использование в программном коде
Начнем с инициализации.
Инициализация Log4J
В простейших случаях об этом можно не заботиться. Как уже упоминалось, конфигурационные файлы ищутся в classpath , сначала XML-вариант, потом файл свойств. И в довольно большом количестве случаев этого достаточно.
Бывают, однако, исключения. Представьте себе, что у вас есть несколько веб-приложений. Каждое из них имеет свой загрузчик классов. А конфигурация лога у всех одинаковая. Вариантов два – либо класть файл конфигурации в каждый веб-архив – что особенно удобно, когда надо обновить конфигурацию лога! – либо держать его в какой-то одной точке, где можно его менять и откуда все приложения будут его читать.
На все такие случаи Log4J предоставляет средства для инициализации вручную. Для этого применяются классы org.apache.log4j.PropertyConfigurator и org.apache.log4j.xml.DOMConfigurator . Эти классы имеют несколько статических методов для инициализации, если быть точным, то их по пять (в версии 1.2.16). Четыре из них совпадают по сигнатурам:
- configure(String configFilename) – инициализирует Log4J на основании указанного имени файла
- configure(java.net.URL configURL) – инициализирует Log4J на основании указанного URL файла
- configureAndWatch(String configFilename) – инициализирует Log4J на основании указанного имени файла и отслеживает изменения, при которых файл перезагружается и происходит переинициализация. Период отслеживания изменений составляет 60 секунд (значение константы org.apache.log4j.helpers.FileWatchdog.DEFAULT_DELAY ).
- configureAndWatch(String configFilename, long delay) – инициализирует Log4J на основании указанного имени файла и отслеживает изменения, при которых файл перезагружается и происходит переинициализация. Период отслеживания изменений задается вторым параметром в методе.
Последний метод специфичен для форматов данных. Он в обоих случаях называется configure , однако в org.apache.log4j.PropertyConfigurator он принимает параметр типа java.util.Properties , а в org.apache.log4j.xml.DOMConfigurator – типа org.w3c.dom.Element . Оба эти метода предназначены для создания конфигурации вручную, в программном коде.
Т.е. вся инициализация Log4J по большому счету сводится к одной единственной строчке:
DOMConfigurator.configure("./log4j.xml");
Советую также посмотреть документацию по классам org.apache.log4j.PropertyConfigurator и org.apache.log4j.xml.DOMConfigurator, ибо я не ставил целью ее копировать и некоторые моменты сознательно опустил.
Теперь об использовании логгеров в коде.
Использование логгеров
Инициализация логгера производится тривиально, тоже статическими методами:
- Logger.getLogger(Class clazz) – инициализация по классу. Наиболее распространенный вариант. Имя категории принимается равным полному имени класса, собственно, внутри вызывается второй метод инициализации с параметром clazz.getName() .
- Logger.getLogger(String categoryName) – более общий вариант. Возвращается логгер по указанному имени, которое в общем случае может не совпадать с именем класса. Этот метод может быть полезен, если есть необходимость в разных классах выводить сообщения в одной категории.
Как правило, логгеры получаются в каждом классе, где они нужны, по одному на класс:
private static final Logger logger = Logger.getLogger(MyClass.class);
Это позволяет наиболее эффективно конфигурировать уровень лога и разводить сообщения по разным файлам. Если же есть необходимость, например, все относящиеся к работе с БД сообщения конфирурировать синхронно, вне зависимости от того, где они генерируются – можно ввести одну категорию и получить под нее собственный логгер:
private static final Logger logger = Logger.getLogger(MyClass.class); private static final Logger dbLogger = Logger.getLogger("ru.skipy.DB");
И в этом случае конфигурация для этой категории не будет пересекаться с конфигурацией для остального лога данного класса. Так сделано, например, в Hibernate, с категорией org.hibernate.SQL , которая используется для вывода логов, связанных с SQL, из любой точки библиотеки. Но такой подход достаточно редок.
На всякий случай уточняю: имя категории совсем не обязательно должно начинаться с имени пакета – ru.skipy . Точно так же я мог указать в качестве имени my_favorite_DB_category или my.favorite.DB.category – все эти варианты будут работать идентично.
Использование логгера в коде тоже не вызывает сложностей – просто вызывается соответствующий метод:
logger.info("Starting mass rate charge calculation. ");
В случае обработки исключения – вторым параметром передается оно:
try< // код, вызывающий исключение >catch(RateCalculationException ex)< logger.error("Error while calculating rate change!", ex); >
Есть, однако, тонкость, связанная с использованием уровней DEBUG и TRACE . Дело тут в двух моментах:
-
Количество данных, выводимых на уровне DEBUG и, тем более, TRACE , достаточно велико. Причем выводятся, как правило, не только сообщения, но и множество параметров внутреннего состояния, в чем, собственно, и заключается смысл такого подробного лога:
logger.debug("Starting rate charge calculation for account " + accountNum + " with parameters: rest var">rest + ", percent var">percent + " period var">period);
То есть что получается. Мы сначала формируем сообщение, а о том, что лог запрещен, узнаем только потом. Когда время на создание сообщения уже потрачено. Мы можем использовать StringBuilder , MessageFormat и что угодно еще – кардинально ситуацию это не изменит. Мы в любом случае тратим достаточно времени впустую. А сообщений на уровне DEBUG выводится много.
Так вот, чтобы этого избежать, в логгере существуют два метода – isDebugEnabled() и isTraceEnabled() . Они позволяют сначала проверить, имеет ли смысл вообще создавать сообщение, и только потом тратить на это время, когда понятно, что оно будет потрачено не зря. Т.е. фрагмент кода, приведенный выше, должен выглядеть так:
if (logger.isDebugEnabled())< logger.debug("Starting rate charge calculation for account " + accountNum + " with parameters: rest var">rest + ", percent var">percent + ", period var">period); >
Использование такой конструкции крайне рекомендуется. И то же самое относится к TRACE .
Больше, пожалуй тонких моментов я не встречал. Если знаете – пишите, с удовольствием включу в статью.
Переходим к следующему разделу.
NDC – Nested Diagnostic Context
За работу с NDC отвечает класс по имени org.apache.log4j.NDC . Использовать его очень просто. Для добавления информации в контекст вызывается статический метод NDC.push(String) . Передаваемый параметр помещается на вершину стека, откуда его можно – и нужно! – удалить при помощи другого статического метода – NDC.pop() . Эти методы необходимо применять парно, чтобы не вызывать перекосов (накапливания или исчерпания стека).
Еще одно правило, исполнения которого требует Log4J – при завершении работы в потоке вызывать метод NDC.remove() . В принципе, ничего страшного не произойдет, если вы этого не сделаете, однако контекст останется присоединеным к потоку, и если вы «забудете» там данные – они попадут в следующий запрос, обрабатываемый этим потоком, запутав вас еще больше.
Таким образом, использование NDC выглядит примерно так (на примере doGet сервлета):
public void doGet(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException< NDC.push(getUserName()); // тут выполняем какие-то действия doWork(); // вызываем метод // тут выполняем какие-то действия NDC.pop(); NDC.remove(); > private void doWork()< NDC.push(getPermissions()); // тут выполняем какие-то действия NDC.pop(); >
Для вывода NDC в лог можно использовать либо TTCCLayout, либо PatternLayout и опцию %x . В логе в результате появится стек в виде строк, разделенных пробелами (использован формат %d %p [%x] %m%n ):
NDC.push("aaa"); NDC.push("bbb"); NDC.push("ccc"); logger.info("My message");
2010-05-27 22:52:15,909 INFO [aaa bbb ccc] My message
Позиционное форматирование на опцию %x действует. При этом строка, представляющая стек, обрезается с начала. Т.е. если ограничить в примере выше длину NDC 10-ю символами ( %.10x ), то в лог будет выведена строка aa bbb ccc . Таким образом, всегда видна вершина стека.
Желающие могут более подробно ознакомиться с NDC вот тут: http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/NDC.html. А мы переходим ко второму типу диагностического контекста –
MDC – Mapped Diagnostic Context
За работу с MDC отвечает класс по имени org.apache.log4j.MDC . Использовать его не сложнее, чем NDC. У MDC есть следующие статические методы:
- put(String,Object) – помещает в контекст объект под соответствующим именем.
- remove(String) – удаляет из контекста объект под соответствующим именем
- get(String) – получает из контекста объект под соответствующим именем (не удаляя)
- clear() – очищает контекст
Принципы использования MDC те же, что и у NDC. put и remove используются парами, перед завершением работы в потоке вызывается clear . Пример кода даже приводить не буду.
За вывод MDC в лог отвечает опция %X . На нее также распространяется позиционное форматирование, и строка обрезается тоже сначала. Однако, поскольку порядок элементов в строковом представлении для MDC не определен – предсказать, что именно будет видно в логе, невозможно. Формат вывода в лог следующий (используется шаблон %d %p [%X] %m%n ):
MDC.put("key1", "value1"); MDC.put("key2", "value2"); MDC.put("key3", "value3"); logger.info("My message");
2010-05-27 23:27:52,636 INFO [>] My message
Хочу еще раз напомнить, что %X работает только при использовании EnhancedPatternLayout, обычный PatternLayout требует указания ключа и не может вывести контекст целиком. Разумеется, EnhancedPatternLayout с ключами тоже умеет работать.
И последняя тема –
Управление во время исполнения
Эта часть посвящена исполнению озвученной в начале мечты – «идеальной была бы ситуация, когда количество выводимых данных можно было бы менять как нужно, и в тот момент, когда нужно». При минимальных усилиях можно добиться и этого.
Отталкиваться будем от того, что каждому логгеру можно выставить уровень. В программном коде. Использовать для этого надо метод логгера setLevel(org.apache.log4j.Level) .
Метод есть – это хорошо, полдела сделано. Однако его еще надо как-то вызвать. Мне в этом отношении ближе всего использование технологии JMX – Java Management Extension. Подробно в нее погружаться не буду, из примера все понятно.
Я еще несколько упрощу задачу – буду считать, что имя категории, которой надо менять уровень, известно. В принципе, это не лишено смысла. Достаточно редко бывает необходимость изменить уровень произвольного логгера, чаще это запросы типа «а давайте-ка посмотрим, что у нас творится в работе с БД». А работа с БД – это набор логгеров. И проще где-то его прописать, чем заставлять конечного пользователя вводить все эти длинные и бесссмысленные на его взгляд имена.
В общем, тестовое приложение устроено так. Создается один management bean с функциями установки уровня – от TRACE до FATAL. Реализация этих функций устанавливает предопределенному логгеру этот уровень. Еще раз повторюсь, ничего не мешает передать имя логгера в приложение, если в этом возникнет необходимость. Его просто надо будет сделать параметром вызываемой функции.
Соединение с приложением и вызов функций можно выполнять из любого JMX-клиента. В Java Runtime Environment такой клиент тоже есть, это JConsole. Он позволяет подключиться к виртуальной машине и в числе прочего вызывать ее JMX-функции. Чем мы и воспользуемся.
Всего кода я тут приводить не буду, только отдельные фрагменты.
Определение интерфейса для JMX:
/** * MBean interface definition */ public static interface Log4JManagerMBean < /** * Setting log level to
TRACE*/ public void setTraceLevel(); // для остальных уровней аналогично >Реализация этого интерфейса:
/** * MBean implementation */ public static class Log4JManager implements Log4JManagerMBean< /** * Returns instance of the logger for category
ru.skipy.logging* * @return logger instance */ private Logger getLogger()< return LogManager.getLogger("ru.skipy.logging"); > /** * Setting log level toTRACE*/ @Override public void setTraceLevel() < getLogger().setLevel(Level.TRACE); > // для остальных уровней аналогично >И регистрация созданного management bean-а:
public static final String OBJECT_NAME = "ru.skipy.logging.jmx:type=Log4J JMX Manager"; /** * Initializes MBean with the object name #OBJECT_NAME> * * @throws Exception if any error occures */ private static void initMBean() throws Exception< MBeanServer mbs = ManagementFactory.getPlatformMBeanServer(); ObjectName name = new ObjectName(OBJECT_NAME); Log4JManager mbean = new Log4JManager(); mbs.registerMBean(mbean, name); >
А дальше – можно выводить сообщения на всех уровнях и смотреть на результат.
/** * Testing all log levels */ private void test() < System.out.println("Testing all levels:\n=================== static_final">.out.println("Trace: "); if (logger.isTraceEnabled())< logger.trace("TRACE message"); > System.out.println("Debug: "); if (logger.isDebugEnabled())< logger.debug("DEBUG message"); > System.out.println("Info: "); logger.info("INFO message"); System.out.println("Warn: "); logger.warn("WARN message"); System.out.println("Error: "); logger.error("ERROR message"); System.out.println("Fatal: "); logger.fatal("FATAL message"); System.out.println("Done\n=================== logging.zip">скачать. Для компиляции и запуска потребуется еще сама библиотека log4j-1.2.16.jar. Предпочтительно ее, конечно, скачать с сайта Log4J (http://logging.apache.org/log4j/1.2/download.html), если такой возможности нет – можно взять тут.

Краткая инструкция по запуску примера.
Скачиваем архив, распаковываем, собираем. Команда для запуска примера –
ant run. Появится окно, которое сейчас находится слева. Обратите внимание на значение Process ID – оно необходимо для надежной идентификации процесса в JConsole.Далее запускаем JConsole. Это приложение входит в поставку Java SDK, находится в директории
/bin. Появляется окно логина. Находим в нем процесс с указанным ID, соединяемся (жмем кнопку Connect).Последняя закладка JConsole – MBeans. Находим там management bean, соответствующий имени, которое мы указали в коде – ru.skipy.logging.jmx:type=Log4J JMX Manager. Открываем в дереве ветку Operations и видим все операции, которые мы определили для изменения уровня.

Снимок окна JConsole приведен слева. В его правой части виден список операций. Для выполнения соответствующей операции достаточно нажать на кнопку с ее именем. Собственно, в этом и заключается смысл примера – поочередно устанавливать различные уровни лога, нажимать "Press to test log. " в тестовом приложении и наблюдать, как изменится вывод в лог.
Ниже приведен пример вывода в консоль после нажатия кнопки в приложении в изначальном состоянии (сразу после запуска), и дальше – после установки уровней
TRACEиFATAL. Изначально был установлен уровеньINFO, соответственно, сообщения на уровняхTRACEиDEBUGвидны не были. Далее установили уровеньTRACE– стали видны все сообщения. После установки уровняFATALвидно только сообщение на этом уровне, остальные сообщения до консоли не дошли.[java] Testing all levels: [java] ==================== [java] Trace: [java] Debug: [java] Info: [java] 2010-05-30 13:14:09,720 [INFO ] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - INFO message [java] Warn: [java] 2010-05-30 13:14:09,720 [WARN ] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - WARN message [java] Error: [java] 2010-05-30 13:14:09,720 [ERROR] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - ERROR message [java] Fatal: [java] 2010-05-30 13:14:09,720 [FATAL] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - FATAL message [java] Done [java] ==================== [java] Testing all levels: [java] ==================== [java] Trace: [java] 2010-05-30 13:14:17,798 [TRACE] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - TRACE message [java] Debug: [java] 2010-05-30 13:14:17,798 [DEBUG] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - DEBUG message [java] Info: [java] 2010-05-30 13:14:17,798 [INFO ] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - INFO message [java] Warn: [java] 2010-05-30 13:14:17,798 [WARN ] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - WARN message [java] Error: [java] 2010-05-30 13:14:17,798 [ERROR] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - ERROR message [java] Fatal: [java] 2010-05-30 13:14:17,798 [FATAL] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - FATAL message [java] Done [java] ==================== [java] Testing all levels: [java] ==================== [java] Trace: [java] Debug: [java] Info: [java] Warn: [java] Error: [java] Fatal: [java] 2010-05-30 13:14:21,579 [FATAL] [AWT-EventQueue-0 ] [ru.skipy.logging.jmx.Main] - FATAL message [java] Done [java] ====================
Вот так, почти что тривиальный код позволяет эффективно управлять выводим в лог, не останавливая приложения. Более того, мы можем реализовать возможность указывать имя логгера, уровень вывода для которого мы хотим изменить. И тогда мы сможем установить вообще любой уровень для любого логгера. Гибкость максимальная, удобство обсуждаемо.
Послесловие
Вот, пожалуй, и все, что я хотел рассказать о логировании как явлении вообще и о Log4J в частности. Я не затронул довольно много тем – собственные обработчики ошибок, фильтры, преобразователи (renderers) объектов, переинициализацию всей системы логирования во время исполнения, использование системных и собственных свойств в файле свойств Log4J. Я не углублялся в другие фреймворки, хотя, например, Logback тоже весьма интересен, тем более, что он представляет собой развитие Log4J.
Я не сделал всего этого по той причине, что где-то все-таки надо провести логическую черту. Того, что я рассказал, должно с лихвой хватить для освоения Log4J в частности и понимания принципов логирования вообще. Если кому-то интересно – после этого материала он вполне сможет продолжить изучение самостоятельно. Я же на текущий момент считаю свою задачу выполненной.
Всем спасибо! Надеюсь, это было полезно.
P.S. Для вопросов, комментариев и обсуждения создана страница в блоге: http://skipy-ru.livejournal.com/2980.html.
1. Слово log в английском имеет множество значений, в том числе протокол или журнал. В русском успешно прижилось само слово лог и производные от него логирование и логировать. Хотя правильнее было бы говорить журналирование (протоколирование) и вести журнал (протокол) соответственно. В этой статье я буду употреблять прижившиеся термины.
2. На самом деле я их знаю больше, чем три. Есть еще LogKit, бывший частью проекта Apache Avalon, есть еще логгер в самом Avalon, который тоже является зонтичным и является уровнем абстракции для LogKit, java.util.logging и Log4J. Есть Lumberjack – фреймворк для логирования в Java версии до 1.4 И т.д. и т.п. На раннем этапе, когда ниша логгеров не была занята, разрабатывалось много разных фреймворков. Однако практически все они уже отмерли, потому я их даже не упоминаю.
3. NOP (No Op) – сокращение отNo Operation. Такой логгер не осуществляет никакого вывода информации – все его методы имеют пустую реализацию. Нужен для того, чтобы минимизировать затраты на логирование, когда оно не нужно.
4. Вот, например, неплохая статья по этому поводу: http://articles.qos.ch/classloader.html.
5. Последняя версия – 1.2.16 – вышла 7 апреля 2010, 1.2.15 – 30 августа 2007, 1.2.14 – 18 сентября 2006. Информация из архива версий Log4J: http://archive.apache.org/dist/logging/log4j/.
Copyright © 2004-2013 Евгений Матюшкин aka Skipy (e-mail: skiрyskipy.ru)
Копирование и воспроизведение материалов этого сайта возможно только с согласия автора!