Введение в Log4J

Для ведения лога, как я вижу, чаще используют Log4j, как минимум в тех проектах где я участвовал это стандарт. Но при первом знакомстве с ним у многих возникают проблемы с пониманием того как это работает и как его использовать. Я на самом деле ни разу не понимаю почему log4j вызывает такие трудности... потому попробую объяснить.

Java код

Начиная писать класс, первой строкой я обычно пишу:

private static final Logger log = Logger.getLogger(ТекущийКласс.class);

И даже забиваю это в шаблоны создания класса, умная ide сама сможет подставить ТекущийКласс (это уже в хелпе смотрите).

Что делает эта строка: создает нам объект которым мы можем писать лог, читая все настройки для данного логгера. О настройках позднее.

Позже мы можем писать следующее:

log.debug("Start processing");
//код
if (log.isDebugEnabled()) {
    log.debug("Result: "+result);
}
//код
try {
//код
} catch (Exception e) {
    log.error("Something failed", e);
}
//код
log.debug("done");

т.е. у log есть методы .debug(), .info(), .warn(), .error(), .fatal() которые передают в лог сообщения с соответствующем уровнем.

В случае если у нас сообщение для лога строится из нескольких строк, или вообще делается какая то операция, то лучше перед этим сделать проверку на то что данный уровень логгирования в данный момент включён, методом isУровеньEnabled (как в примере isDebugEnabled ()). Это стоит проверять для того чтобы не выполнять лишние операции когда результат нам просто далее не понадобится. Если пишется просто строка то нет смысла проверять уровень, внутри log4j и так все проверится и не пройдёт в лог если он выключен. Ещё, как видно в примере, можно туда же передать exception, и log4j выведет stacktrace в лог.

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

Настройка log4j

Самой простой настройкой будет положить файлик log4j.properties в classpath нашего приложения, и все описать в нем. В classpath означает в его корне, т.е. если у вас все берётся из ./classes то должен быть ./classes/log4j.properties. Туда скопировать может и ide, из директории с исходным и файлами, т.е. если у вас исходники хранятся в ./src, то создайте ./src/log4j.properties, при компиляции среда сама скопирует файла в директорию с классами.

Пример настройки log4j в этом файле:

log4j.rootLogger=warn, stdout, file

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.conversionPattern=%d{ABSOLUTE} %5p %t %c{1}:%M:%L - %m%n

log4j.appender.file=org.apache.log4j.FileAppender
log4j.appender.file.file=myproject.log
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.conversionPattern=%d{ABSOLUTE} %5p %t %c{1}:%M:%L - %m%n

log4j.appender.debugfile=org.apache.log4j.FileAppender
log4j.appender.debugfile.file=myproject-debug.log
log4j.appender.debugfile.layout=org.apache.log4j.PatternLayout
log4j.appender.debugfile.layout.conversionPattern=%d{ABSOLUTE} %5p %t %c{1}:%M:%L - %m%n
log4j.logger.com.my.app.somepackage=DEBUG, debugfile
log4j.logger.com.my.app.somepackage.subpackage.ClassName=INFO

Вот тут да, сразу не совсем понятно 🙂 Буду объяснять. Запись

log4j.rootLogger=warn, stdout, file

настраивает логгер по умолчанию, первый элементом идет уровень сообщений который нужно перехватывать (и все выше него), в данном случае это warn, т.е. уровни info и debug в лог не пойдут, а warn, error и fatal будут в логе. Следующие два элемента это названия appender'ов, настроек с помощью которых вести лог, они настроены ниже.
В этой строке:

log4j.appender.stdout=org.apache.log4j.ConsoleAppender

мы настраиваем appender с именем stdout, указывая что для него будет использоваться класс org.apache.log4j.ConsoleAppender, это простой класс который выводит лог в консоль приложения. Далее строки, начинающиеся с log4j.appender.stdout. настраивают этот appender. Все что идет после указанного префикса должно совпадать со свойством класса, т.е. для target должен быть метод setTarget, для layout метод setLayout ну и т.д.

Шаблон(layout) вывода лога

А вот layout это тоже очень интересная штука, он определяет как форматировать вывод в лог. В примере выше для этого используется класс org.apache.log4j.PatternLayout, и мне, честно говоря, даже не приходило в голову проверять есть ли другие форматтеры, т.к. его всегда было достаточно. Возможно для лога в какой-нибудь xml и понадобится другой форматтер, но имхо это совсем редкость. Так вот, данный форматтер принимает параметром conversionPattern, шаблон вывода лога, о нем подробней:

%d{ABSOLUTE}
Выводит время. В скобках можно указать формат вывода, о нем подробней можно прочитать в хэлпе к стандартному классу SimpleDateFormat. И еще можно использовать именованные шаблоны, как в данном случае, это ISO8601 и ABSOLUTE. Последний означает формат HH:mm:ss,SSS, по мне так наиболее удобный вид для лога, если они не хранятся неделями и месяцами.
%5p
Выводит уровень лога (ERROR, DEBUG, INFO и пр.), цифра 5 означает что всегда использовать 5 символов, остальное дополнится пробелами
%t
Выводит имя потока который вывел сообщение
%c{1}
Категория, в скобках указывается сколько уровней выдавать. Категорией в нашем случае будет имя класса с пакетом. Ну а вообще это строка, где уровни разделены точками. Т.к. у нас совпадает с полным именем класса, то верхний уровень будет являться именем класса
%M
Имя метода в котором произошёл вызов записи в лог
%L
Номер строки в которой произошёл вызов записи в лог
%m
Сообщение, которое передали в лог
%n
Перевод строки

Более подробно модно посмотреть в JavaDoc для класса PatternLayout.
На самом деле можно не вдаваться в подробности этого шаблона, а использовать именно тот который у меня в примере, он у меня кучу лет как через copy & paste пишется, и всегда его хватало.

Вернемся к настройке

Еще остались:

log4j.appender.stdout.target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.conversionPattern=%d{ABSOLUTE} %5p %t %c{1}:%M:%L - %m%n

и

log4j.appender.file=org.apache.log4j.FileAppender
log4j.appender.file.file=myproject.log
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.conversionPattern=%d{ABSOLUTE} %5p %t %c{1}:%M:%L - %m%n

В данных случах это log4j.appender.<ИМЯ_АППЕНДЕРА>.<СВОЙСТВО>=<ЗНАЧЕНИЕ>. Под свойством я подразумеваю методы setИмяСвойства, т.е. стандартные Java Bean Property. Заморачиваться тут тоже не стоит, настройки обычно похожие, различие лишь в том что для file мы задаем имя файла (в примере это myproject.log). Ну а для прочих реализаций аппендера все свойства прекрасно видны в JavaDoc.

Ну а FileAppender соответсвенно пишет в файл, думаю это и по названию понятно.

Настройки вывода для классов

И последним у меня идет настрйока того как выводить в лог для отдельных классов и пакетов:

log4j.logger.com.my.app.somepackage=DEBUG, debugfile
log4j.logger.com.my.app.somepackage.subpackage.ClassName=INFO

Принцип такой:

log4j.logger.<ИМЯ_ПАКЕТА>.<ИМЯ_КЛАССА>= <УРОВЕНЬ>, <ИМЯ_ЛОГГЕРА>

или как чаще бывает:

log4j.logger.<ИМЯ_ПАКЕТА>= <УРОВЕНЬ>

т.е. таким вот образом мы индивидуально указывает для пакета, или даже класса, как писать лог, какой уровень минимальный и нужно ли писать в дополнительный аппендер (к примеру в дополнительынй файл).
log4j.logger.com.my.app.somepackage=DEBUG, debugfile указывает что для пакета com.my.app.somepackage нашего приложения выводить все, т.е. все начиная с уровня debug, и при этом еще писать в файл настроенный в аппендере debugfile (см. в самом первом примере). А log4j.logger.com.my.app.somepackage.subpackage.ClassName=INFO указывает определенный класс, для которого выводить все сообщения начиная с уровня info, при этом не указывая никакого дополнительного аппендера, а значит будут использовать те которые настроены в rootLogger (т.е. вывод в стандартный поток вывода, это к примеру на экран, и вывод в файл)

Настройки уровней и логгеров идут от rootLogger а далее по пакетам и классам. Получается мы можем сделать одни настройки для пакета com.company.project, а потом расширить эти настройки для пакета com.company.project.foobar

Краткое повторение

Все эти «много букв» это хорошо, но для простоты краткий туториал:

Головная настрйока, в которой укажем что выводить лишь warn. По умолчанию нам больше и не надо, к примеру потому что в проекте явно попадутся сторонние библиотеки использующие log4j, и этим самым мы и их настраиваем, а нам не надо кучу ненужного debug вывода от какого нибудь spring или hibernate. И так, первая строка:

log4j.rootLogger=warn, stdout

Далее настройм упомянуутый в этой строке вывод в stdout:

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.conversionPattern=%d{ABSOLUTE} %5p %t %c{1}:%M:%L - %m%n

А вот теперь мы можем настраивать что у нас выводить, по умолчанию включим info для нашего проекта, к примеру наш проект весь расположен в пакете com.microsoft.msn:

log4j.logger.com.microsoft.msn=INFO

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

log4j.logger.com.microsoft.msn.blogs.account=DEBUG

Если же вдруг оказалось что в нашем пакете есть класс, к примеру ProfileInfo, который нам сейчас совем не важен, но он выводит кучу debug сообщений в лог, то выключим его:

log4j.logger.com.microsoft.msn.blogs.account.ProfileInfo=INFO

или даже:

log4j.logger.com.microsoft.msn.blogs.account.ProfileInfo=ERROR

что значит что мы увидим лишь совсем редкие записи, с уровнем ERROR и FATAL

Ну собсвенно все, можно складывать файлик в src/ или, если точнее, в classes/, но это за нас уже умная IDE сделает при компиляции.

Возникающие сложности

Часто возникает проблема в том что подключаются какието непонятные настройки, явно не наши, или вовсе никакие не подключаются. Причина этого в том что или в classpath попал еще один log4j.properties, или вовсе не попал. Первое запросто, мы всегда подключаем кучу jar'ов да и просто диреткорий с классами, и вполне возможно что туда попал чужой файл. Тут нужно сделать чтобы classpath с нашим log4.properties был первым, или можно удалить все лишние файлы.
А вот проблема с тем что нет в classpath это уже... ну в общем оно индивидуально всегда, и означает что чтото вы неправильно собрали 🙂 Смотрите что у вас в настрйока среды разработки, в анте, мавене и пр., смотря чем собираете приложение.

PS: как то слово appender можно на русский перевести?

  • http:// afimov

    Он еще может конфигуриться с помощью XML. Там, имхо, наглядней.

    А еще, в качестве опыта, я понял, что правильней использовать «набор» логгеров в одном классе или в Enume , чтобы не писать в каждом классе Logger.getLogger.

    Будет чтото типа:

    Loggers.DB.debug (...)

    Loggers.UI.debug (...)

    И т.п.

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

    Вот.

  • http:// igor

    А чтото в этом есть, в отдельном классе и сроках. Надо подумать 🙂 Вот только непривычно как то.

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

  • http:// Ivan Tarasov

    У меня единственный вопрос: а почему бы не воспользоваться стандартными средствами предоставляемыми Java-платформой (т.е. java.util.logging)?

    С log4j у меня как-то раз была сложно-диагностируемая проблема с ThreadDeath, в результате просто перевели проект на j.u.l.

  • http:// igor

    А это уже привычка, j.u.l ведь не всегда был.

    И честно говоря просто лень смотреть его, т.к. log4j полностью устраивает, не вижу смысла начинать проект (ведь не просто в существующий встроить) с ним, мало ли что потом.

  • http:// Ivan Tarasov

    Ну так, мир не стоит на месте 🙂

    а с j.u.l вряд ли уже что-то плохое произойдёт. Из плюсов его использования: Java тоже кидает свои логи в j.u.l (правда они отключены by default), так что их можно ловить той же системой, что и логи приложения.

  • http:// igor

    А j.u.l что то новое даст, или просто отнимет время без какого либо дополнительного положительного эффекта?

  • http:// Петр

    Игорь, а не приходилось ли настраивать логирование во временный файл? Сейчас наткнулся на интересный момент, требуется, чтобы текущий лог-файл был с расширением tmp, а при выполнении ротации расширение нужно изменить. Умеет ли такое делать log4j? Если какие-то интересные мысли на эту тему, буду рад услышать.

  • http:// igor

    Т.е. то что делает RollingFileAppender это не подходит? Иначе надо будет писать свой аппендер.

  • http:// Петр

    Спасибо за ответ. Да нужна расширенная функциональность RollingFileAppender с кастомным именем/расширением файла лога. Возможно буду писать свой Appender 🙂

  • http:// xeye

    в данном контексте appender следует переводить как «канал» 🙂

    jdk логгинг ничего нового не дает... разве что возможность глбоального конфигурения через jre\lib\logging.properties

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

    мне смешно видеть проекты, которые давно работают на 1.5 минимум и используют loggings-common, типа, «а вдруг стандартного логгинга не будет». уж определились бы, или то или сё...

  • http:// Vera Tkachenko

    IMHO, appender просто тот, кто добавляет (производное от to append = добавлять ) в нашем случае в лог.

  • http:// agerman

    использую Log4J через Apache Commons Logging. Такой подход предоставляет возмножность менять подсистему логгинга не меняя кода приложения.

  • http:// igor

    Антон, а если честно, сколько раз реально тебе эта прослойка помогла сменить log4j на чтото другое. Точнее наверное наоборот: что было до log4j и благодаря этой прослойке легко сменили на него?

    И насколько вероятно что возможностей log4j нехватит для текущего проекта и нужно будет перейти на другой логгер?

  • http:// Dima

    Такой вопрос: Как настроить чтобы из ОДНОГО класса логгер писал логи в разные файлы

    Например в System.log и Application.log.

  • http:// Nuru

    Очень полезная статья, спасибо!

  • http:// Kvp

    2Dima

    private static final Logger logSystem = Logger.getLogger («SystemLog»);

    private static final Logger logApp = Logger.getLogger («AppLog»);

    ...

    logSystem.debug («Так»);

    logApp.debug («Сяк»);

    ------

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

  • http:// black zorro

    В дополнение к вашему посту. В составе доступных Handeler-ов в java.util.logging есть очень интересный вариант: MemoryHandler.

    Его назначение складывать приходящие записи от Logger-а во внутренний буфер (это работает достаточно быстро т.к. не вызываются Formatter-ы)

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

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

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

    Фактически MemoryHandler идеальное решение: вы ставите максимальный уровень подробности сообщений, но они не выводятся и не засоряют лог, а как только пришло сообщение с уровнем SEVERE,

    то в лог будут сброшены например последние 10 сообщений.

    вот пример код, надеюсь, кому-нибудь он пригодится:

    Наученный горьким опытом wordpress-а не рискую сюда вставлять пример исходника. Вставьте пожалуйста его сами с сайта-кода-пасты:

    paste.bradleygill.com/index.php?paste_id=186

  • http:// Andrey

    А есть ли возможность каким-то образом при отсутствии log4j.properties (или если он некорректно настроен) вести лог куда-нибудь в память? Пусть даже в свой какой-нибудь Memory Appender ограниченный буфером, а после где-то в программе получить этот вывод?

  • http:// igor

    Можно и в коде настроить, без log4j.properties, но это совсем геморой получается. Ну а настроить (в том числе без log4j.properties) можно чтобы и в память складывал.

  • http:// paxus

    «Такой вопрос: Как настроить чтобы из ОДНОГО класса логгер писал логи в разные файлы»

    «2Dima

    private static final Logger logSystem = Logger.getLogger (”SystemLog”);

    private static final Logger logApp = Logger.getLogger (”AppLog”);

    logSystem.debug (”Так”);

    logApp.debug (”Сяк”);»

    А разве нельзя обойтись одним логгером в коде, но указать в log4j.properties несколько файловых аппендеров для данного класса? как, собсно, в примере?

    Я еще только разбираюсь, вопрос заинтересовал

  • http:// Ivan

    Можно ли настроить log4j.properties таким образом, что бы в качестве имени лог-файла была текущая дата в формате (dd-MM-yyyy) и при изменении текущей даты создавался бы новый лог-файл с именем (dd-MM-yyyy)?

  • http:// igor

    Да, точно можно, делал когдато. Сейчас не вспомню точно что использовал, но помоему расширял FileAppender

  • http:// Ivan

    А как расширял? Примерчик бы подкинул, если не сложно конечно?

  • http:// igor

    Вообще по поводу расширения аппендера тут: artamonov.ru/2006/01/27/appender-dlya-log4j/

    Хотя в случае файла все на порядок проще. Но примерчик не могу подкинуть, нет доступа к тому коду чтобы посмотреть. Помнится в log4j.properties был указан DateFormat паттерн имени файла, ну и дальше в том же духе, думаю разберешься.

  • http:// Ivan

    Если кому-то надо: DailyRollingFileAppender использовал его и DateFormat — указывал формат даты (напр: dd-MM-yyyy)

  • http:// igor

    О, даже так. Спасибо!

  • http:// Herr Reich

    public class MyLogger extends Logger {

    public void debug (String format, Object[] args) {

    if (isDebugEnabled ()) debug (String.format (format, args);

    }

    }

    log.debug («Hello, world from %s», hostname);

  • http:// Александр Нуйкин

    Подскажите пожалуйста, в чем причина того, что следующие настройки выдают одни и те же сообщения по 3 раза (!) при вызовах log.debug () из класса внутри пакета math.mp (или вложенных в него):

    # Root logger: show all - debug, info, error and fatal log4j.rootLogger=debug, stdout # Turn off extra loggers: show only error and fatal log4j.logger.math=error, stdout # Debug only following packages log4j.logger.math.mp=debug, stdout

    И, если можно, как это исправить?

    Кстати, может у настроек коментарии неверные?

    При этом подразумевается, что log создается так, как показано в начале статьи.

  • http://artamonov.ru splix

    Нужно убрать «, stdout» из 2й и 3й настройки

  • http:// Александр Нуйкин

    Спасибо. Теперь суть ошибки ясна.

  • http:// AskarSyzdykov

    Привет, я студент и прохожу практику в компании которая занимается разработкой и тестированием, мне дали задание разобраться с этой библиотекой или чем она является — log4j. Тестируем с помощью программы SoapUI, которая поддерживает язык java.

    Вот подключаю:

    package log4j

    import org.apache.log4j.*

    Где взять log4j.properties, куда его потом ложить после настроек?

  • http:// AskarSyzdykov

    Забыл сказать Java только начал изучать...

  • Pingback: Подключение к проекту Log4j | dev64

  • http:// knzsoft

    Статья оказалась мне очень полезной. Спасибо!

    Относительно перевода для appender. Как программист имеющий опыт работы техническим переводчиков в крупных софтверных гигантов на программах реализации, могу предложить простой вариант. Исходить из буквального перевода слова append, в данном случае, неправильно. Это приведет к тупику. Надо смотреть синонимы в самом английском. Тут можно вспомнить, что в аналогичной системе JSR47 этот объект называется handler. Вариант «обработчик» вполне приемлем для официальной версии перевода запрещающий вводить не устоявшиеся или не всеми признанные жаргонизмы.

    Ну а если от души, то я бы поборолся с редакторами за термин «аппендер». Хотя, как показывает опыт, это не проходит, но, думаю, что это не чем не хуже, чем «адаптер», который стал уже признанным «русским» термином.

  • http:// Virtyoz

    Здравствуйте! Не подскажете, в чём проблема:

    При компиляции Eclipse сообщает об ошибке:

    «Exception in thread „main“ java.lang.NoClassDefFoundError: org/slf4j/ILoggerFactory

    at java.lang.ClassLoader.defineClass1 (Native Method)»

    (ругается на эту строку:

    public static final Logger LOG=Logger.getLogger (test.class);

    Библиотека подключена, Eclipse не подчёркивает определение логера.)

  • http:// max

    нет в класспасе библиотеки slf4j.

    она нужна для log4j

  • http:// fl

    спасибо

  • Pingback: Тестирование и логирование в Java: JUnit & Log4j | Катавасия одного пустомели

  • http:// Aleksandr Belenov

    Для нечто похожего есть DailyRollingFileAppender.

    log4j.logger.rootLogger=INFO, DailyRollingFile, Console

    log4j.appender.DailyRollingFile=org.apache.log4j.DailyRollingFileAppender

    log4j.appender.DailyRollingFile.File=src/main/webapp/logs/log4j-app.log

    log4j.appender.DailyRollingFile.DatePattern='.'yyyy-MM-dd

    log4j.appender.DailyRollingFile.layout=org.apache.log4j.PatternLayout

    log4j.appender.DailyRollingFile.layout.ConversionPattern=%d{ABSOLUTE} %-5p %t %c{1} %M:%L — %m%n

  • http:// Jack Veromeev

    В проекта должна быть папка 'resources'. Туда и закидывай.

  • http:// Jack Veromeev

    А можно ли выводить в консоль DEBUG, а в файл логов INFO?