Логирование ошибок java

Время на прочтение
7 мин

Количество просмотров 233K

В ходе моей работы в компании DataArt я, в числе прочего, занимаюсь менторской деятельностью. В частности это включает в себя проверку учебных заданий сделанных практикантами. В последнее время в заданиях наметилась тенденция «странного» использования логеров. Мы с коллегами решили включить в текст задания ссылку на статью с описанием java logging best practices, но оказалось, что такой статьи в которой бы просто и без лишних деталей на практике объяснялось бы как надо писать в лог на Java, вот так вот с ходу не находится.

Данная статья не содержит каких-то откровений, в ней не рассматриваются тонкости какого либо из многочисленных java logging frameworks. Здесь рассказываю как записать в лог так, чтобы это не вызвало удивления у Ваших коллег, основная цель написания включить ее в список обязательного чтения для практикантов. Если все еще интересно, читайте дальше

Несколько разъяснений.

• Весь код примеров использует java.util.logging framework. Вопрос «Какой из фреймворков логирования ниболее кошерен» я оставлю за кадром. Скажу только что до java.util.logging проще всего дотянуться ибо он уже идет вместе с JRE и на самом деле рассказанное в данной статье с минимальными косметическими правками верно для подавляющего большинства систем логирования.
• В целом рецепты приведенные в данной статье не являются единственно верными, есть моменты о которых можно поспорить, но в целом эти рецепты используются многие годы, многими разработчиками, во многих проектах и они достаточно хороши чтобы им следовать если у Вас нет каких-то совсем уже серьезных возражений.
• В статье не рассматриваются такие «продвинутые» топики как:
  • Конфигурирование уровней для отдельных логеров
  • Форматирования логов
  • Асинхронное логирование
  • Создание собственных уровней логирования в Log4J
  • Контекстное логирование
  • И многое другое
• Слово logging я пишу по русски как логирование с одной буквой «г» в основном потом, что такой вариант перевода чаще встречается
• Советы, что, с каким уровнем логировать я пожалуй тоже оставлю за кадром т.к. тут все сильно зависит от приложения, условий эксплуатации, отношений с заказчиком и т.п. тонких вещей.

Пример №1

Хорошо

public class SomeClass {
	    
	    private static Logger log = Logger.getLogger(SomeClass.class.getName());
	    
	    public void someMethod()
	    {
	        log.info("Some message");
	    }      
...

1. Логер это статическое поле класса инициализируемое при загрузке класса, имеет простое, короткое имя, важно чтобы во всех Ваших классах переменная логера называлась одинаково (это диктуется общим правилом, одинаковые вещи в программе должны делаться одинаковым образом).
2. В качестве имени логера я использую имя класса, на самом деле это не единственный способ, можно пытаться организовать какую-то свою иерархию логирования (например transport layer/app layer для подсистем имеющих дело с обменом данными), но как показывает практика выдумывать и главное потом неукоснительно следовать такой иерархии крайне сложно, а вариант с именами логеров совпадающими с именами классов весьма хорош и используется в 99% проектов
3. Здесь для записи в лог я использую короткий метод .info, а не более общий метод .log, так много лаконичнее
4. Имя логера берется как 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.fine("Some CPU consuming message: " + prepareCPUConsumingLogMessage());
	        }

1. Если Вам необходимо залогировать исключение, для этого служит метод .log(level,message,exception)
2. Если вы специально не настроили конфигурацию лог системы, сообщения с уровнем ниже info, например fine выводиться не будут. Но писать их по крайней мере для важных частей системы стоит. Когда что-то пойдет не так, Вы настроите более подробный уровень логирования и увидите много интересного.
3. Слишком много лог сообщений, даже если они физически не пишутся в лог файл из-за своего слишком маленького уровня, могут существенно замедлить выполнение программы. Особенно если для подготовки самого сообщения надо потратить много ресурсов. Для этого есть метод .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 и выше.

Выводим лог сообщения куда-то еще

Чем плох вывод на консоль? Консоль это по сути дела старый добрый stderr. Что это значит:

• Если приложение запускается с помощью 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

Последняя часть магии

Ну и последнее о чем осталось рассказать — как собственно сконфигурировать логер из файла свойств. Есть два способа:

1. Из командной строки запуска приложения
2. В первых строчках кода Вашего приложения

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

Вот так

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 как правило в таких случаях кладется в корень иерархии классов и выглядит это например вот так

Что осталось за кадром

В реальной жизни как минимум половина всех Java приложений это web приложения. Сама техничка логирования в них совершенно не отличается от изложенного выше. Ну может быть за тем исключением что разные сервера приложений могут использовать разные библиотеки логирования такие например как:

• Log4J
• JULI logger (строго говоря это не вполне самостоятельный фреймворк, а своего рода надстройка над java.util.logging)
• SLF4J
• Commons Logging

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

• Tomcat
• JBoss
• Resin

Something that I do is to have a static method that handles all exceptions and I add the log to a JOptionPane to show it to the user, but you could write the result to a file in FileWriter wraped in a BufeeredWriter.
For the main static method, to catch the Uncaught Exceptions I do:

SwingUtilities.invokeLater( new Runnable() {
    @Override
    public void run() {
        //Initializations...
    }
});


Thread.setDefaultUncaughtExceptionHandler( 
    new Thread.UncaughtExceptionHandler() {
        @Override
        public void uncaughtException( Thread t, Throwable ex ) {
            handleExceptions( ex, true );
        }
    }
);

And as for the method:

public static void handleExceptions( Throwable ex, boolean shutDown ) {
    JOptionPane.showMessageDialog( null,
        "A CRITICAL ERROR APPENED!n",
        "SYSTEM FAIL",
        JOptionPane.ERROR_MESSAGE );

    StringBuilder sb = new StringBuilder(ex.toString());
    for (StackTraceElement ste : ex.getStackTrace()) {
        sb.append("ntat ").append(ste);
    }


    while( (ex = ex.getCause()) != null ) {
        sb.append("n");
        for (StackTraceElement ste : ex.getStackTrace()) {
            sb.append("ntat ").append(ste);
        }
    }

    String trace = sb.toString();

    JOptionPane.showMessageDialog( null,
        "PLEASE SEND ME THIS ERROR SO THAT I CAN FIX IT. nn" + trace,
        "SYSTEM FAIL",
        JOptionPane.ERROR_MESSAGE);

    if( shutDown ) {
        Runtime.getRuntime().exit( 0 );
    }
}

In you case, instead of «screaming» to the user, you could write a log like I told you before:

String trace = sb.toString();

File file = new File("mylog.txt");
FileWriter myFileWriter = null;
BufferedWriter myBufferedWriter = null;

try {
    //with FileWriter(File file, boolean append) you can writer to 
    //the end of the file
    myFileWriter = new FileWriter( file, true );
    myBufferedWriter = new BufferedWriter( myFileWriter );

    myBufferedWriter.write( trace );
}
catch ( IOException ex1 ) {
    //Do as you want. Do you want to use recursive to handle 
    //this exception? I don't advise that. Trust me...
}
finally {
    try {
        myBufferedWriter.close();
    }
    catch ( IOException ex1 ) {
        //Idem...
    }

    try {
        myFileWriter.close();
    }
    catch ( IOException ex1 ) {
        //Idem...
    }
}

I hope I have helped.

Have a nice day.

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

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

Чтобы избежать таких проблем, логирование в Java упрощается с помощью API, предоставляемого через пакет java.util.logging пакет org.apache.log4j.* .

Компоненты

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

• Loggers – отвечает за сбор записей журнала и передачу их соответствующему заявителю.
• Appenders или Handlers – они отвечают за запись событий журнала в пункт назначения. Аппендеры форматируют события с помощью макетов перед отправкой результатов.
• Layouts или Formatters – отвечает за определение того, как данные выглядят, когда они появляются в записи журнала.

Вы можете обратиться к изображению ниже для работы всех трех компонентов:

Когда приложение выполняет вызов регистрации, компонент Logger записывает событие в LogRecord и перенаправляет его соответствующему Appender. Затем он форматировал запись, используя формат в соответствии с требуемым форматом. Помимо этого, вы также можете использовать более одного фильтра, чтобы указать, какие Appenders следует использовать для событий.

Логгеры (Logger) в Java – это объекты, которые запускают события журнала. Они создаются и вызываются в коде приложения, где генерируют события журнала перед передачей их следующему компоненту, который является Appender.

Вы можете использовать несколько логгеров в одном классе для ответа на различные события или использовать в иерархии. Они обычно называются с использованием иерархического пространства имен, разделенных точками. Кроме того, все имена Logger должны основываться на классе или имени пакета зарегистрированного компонента.

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

Как создать?

Вы должны использовать Logger.getLogger() . Метод getLogger() идентифицирует имя Logger и принимает строку в качестве параметра. Таким образом, если Logger уже существует, он возвращается, в противном случае создается новый.

Синтаксис

static Logger logger = Logger.getLogger(SampleClass.class.getName());

Здесь SampleClass – это имя класса, для которого мы получаем объект Logger.

Пример:

public class Customer{
    private static final Logger LOGGER = Logger.getLogger(Customer.class);
    public void getCustomerDetails() {
    }
}

Уровни

Уровни журналов используются для классификации их по степени серьезности или влиянию на стабильность приложения. Пакет org.apache.log4j.* и java.util.logging предоставляют разные уровни ведения журнала.

Пакет org.apache.log4j.* предоставляет следующие уровни в порядке убывания:

• FATAL;
• ERROR;
• WARN;
• INFO;
• DEBUG.

Пакет java.util.logging предоставляет следующие уровни в порядке убывания:

• SEVERE(HIGHEST LEVEL);
• WARNING;
• INFO;
• CONFIG;
• FINE;
• FINER;
• FINEST(LOWEST LEVEL).

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

Пример с использованием пакета org.apache.log4j.*

import org.apache.log4j.Logger;
public class Customer {
    static Logger logger = Logger.getLogger(Customer.class);
    public static void main(String[] args) { 
	logger.error("ERROR");
        logger.warn("WARNING");	
	logger.fatal("FATAL");
        logger.debug("DEBUG");
        logger.info("INFO");
        System.out.println("Final Output");
    }
}

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

Вы также можете установить уровень с помощью метода setLevel() из пакета java.util.logging , как java.util.logging ниже:

logger.setLevel(Level.WARNING);

Пример с использованием пакета java.util.logging

package edureka;
import java.io.IOException; 
import java.util.logging.Level; 
import java.util.logging.Logger; 
import java.util.logging.*; 
  
class EdurekaLogger { 
    private final static Logger LOGGER =  Logger.getLogger(Logger.GLOBAL_LOGGER_NAME);   
    public void sampleLog() 
    { 
        LOGGER.log(Level.WARNING, "Welcome to Edureka!"); 
    } 
}   
public class Customer { 
    public static void main(String[] args) 
    { 
        EdurekaLogger obj = new EdurekaLogger(); 
        obj.sampleLog(); 
        LogManager slg = LogManager.getLogManager();        
        Logger log = slg.getLogger(Logger.GLOBAL_LOGGER_NAME);   
        log.log(Level.WARNING, "Hi! Welcome from Edureka"); 
    } 
} 

Чтобы включить вход в приложение с помощью пакета org.apache.log4j.* Или пакета java.util.logging , необходимо настроить файл свойств. Далее в этой статье о Logger в Java давайте обсудим файл свойств обоих из них.

Файл свойств пакета Log4j и Java Util

Пример файла свойств Log4j

# Enable Root logger option
log4j.rootLogger=INFO, file, stdout
# Attach appenders to print file
log4j.appender.file=org.apache.log4j.RollingFileAppender
log4j.appender.file.File=E:loglogging.log
log4j.appender.file.MaxFileSize=10MB
log4j.appender.file.MaxBackupIndex=5
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n
# Attach appenders to print on console
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{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n

• Файл свойств Log4j создается внутри папки src проекта.
• log4j.appender.file = org.apache.log4j.RollingFileAppender -> Печатает все журналы в файле
• log4j.appender.stdout = org.apache.log4j.ConsoleAppender -> Печатает все журналы в консоли
• log4j.appender.file.File = D: loglogging.log -> Указывает расположение файла журнала
• log4j.appender.file.MaxFileSize = 10 МБ -> Максимальный размер файла журнала до 10 МБ
• log4j.appender.file.MaxBackupIndex = 5 -> Ограничивает количество файлов резервных копий до 5
• log4j.appender.file.layout = org.apache.log4j.PatternLayout -> Указывает шаблон, в котором журналы будут печататься в файл журнала.
• log4j.appender.file.layout.ConversionPattern =% d {гггг-ММ-дд ЧЧ: мм: сс}% -5p% c {1}:% L -% m% n -> Устанавливает шаблон преобразования по умолчанию.

Пример файла свойств пакета Java Util

handlers= java.util.logging.ConsoleHandler

.level= WARNING

# Output will be stored in the default directory
java.util.logging.FileHandler.pattern = %h/java%u.log
java.util.logging.FileHandler.limit = 60000
java.util.logging.FileHandler.count = 1
java.util.logging.FileHandler.formatter = java.util.logging.XMLFormatter

# Level of logs will be limited to WARNING and above.
java.util.logging.ConsoleHandler.level = WARNING
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter

Здесь

• java.util.logging.FileHandler.pattern =% h / java% u.log -> Файлы журнала будут записаны в C: TEMPjava1.log
• java.util.logging.FileHandler.limit = 50000 -> Максимальная сумма, которую регистратор записывает в один файл в байтах.
• java.util.logging.FileHandler.count = 1 -> Указывает количество выходных файлов
• java.util.logging.FileHandler.formatter = java.util.logging.XMLFormatter -> Упоминает форматер, используемый для форматирования. Здесь используется XML Formatter.
• java.util.logging.ConsoleHandler.level = WARNING -> Устанавливает уровень журнала по умолчанию для WARNING
• java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter -> Указывает форматер, используемый всеми ConsoleHandler. Здесь используется SimpleFormatter.

Регистрация событий

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

Способ 1

logger.log(Level.INFO, “Display message”);

Here, level is INFO and the message to be printed is "Display Message".

Способ 2

logger.info(“Display message”);

Чтобы убедиться, что Logger регистрирует только события, которые находятся на уровне или выше уровня INFO, вы можете использовать метод setLevel(), описанный выше.

Appender или Handlers

Appender или Handlers отвечают за запись событий журнала в пункт назначения. Каждый регистратор имеет доступ к нескольким обработчикам и получает сообщение журнала от регистратора. Затем Appenders используют средства форматирования или макеты для форматирования событий и отправки их в соответствующее место назначения.

Appender можно отключить с помощью метода setLevel (Level.OFF). Два наиболее стандартных обработчика в пакете java.util.logging :

• FileHandler: записать сообщение журнала в файл.
• ConsoleHandler: записывает сообщение журнала в консоль.

Layout или Formatters

Используются для форматирования и преобразования данных в журнале событий. Каркасы журналов предоставляют макеты для HTML, XML, Syslog, JSON, простого текста и других журналов.