Java logging log format

Логирование в Java / quick start

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

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

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

  Пример №1

  Хорошо

  1. Логер это статическое поле класса инициализируемое при загрузке класса, имеет простое, короткое имя, важно чтобы во всех Ваших классах переменная логера называлась одинаково (это диктуется общим правилом, одинаковые вещи в программе должны делаться одинаковым образом).
  2. В качестве имени логера я использую имя класса, на самом деле это не единственный способ, можно пытаться организовать какую-то свою иерархию логирования (например transport layer/app layer для подсистем имеющих дело с обменом данными), но как показывает практика выдумывать и главное потом неукоснительно следовать такой иерархии крайне сложно, а вариант с именами логеров совпадающими с именами классов весьма хорош и используется в 99% проектов
  3. Здесь для записи в лог я использую короткий метод .info, а не более общий метод .log, так много лаконичнее
  4. Имя логера берется как SomeClass.class.getName(), а не как «com.dataart.demo.java.logging.SomeClass», оба способа по идее одинаковы, но первый защищает Вас от сюрпризов при рефакторинге имени/пакета класса

  Плохо

  По сути тоже самое но букв больше и читается не так легко.

  Замечание между примерами

  Вы наверное обратили внимание, что все сообщения в примерах на английском языке. Это не случайно. Дело в том, что даже если все-все кто работает и будет работать с Вашим кодом говорят по русски, есть вероятность, что Вам придется просматривать лог сообщения на удаленном компьютере например через 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))

  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 и выше.

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

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

  Источник

  Java Util Logging — Customizing log format

  By default Java Util logging (JUL) uses following configurations (JDK 8):

  handlers= java.util.logging.ConsoleHandler .level= INFO java.util.logging.ConsoleHandler.level = INFO java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter

  The complete default configuration file can be found at the JDK/JRE installation directory: JAVA_HOME/jre/lib/logging.properties .

  The default handler, ConsoleHandler , sends log records to System.err (the available command line console). This handler, by default uses SimpleFormatter to format logs. In this tutorial, we will learn how to modify the default log format.

  The default formatter, SimpleFormatter , formats the output by using following method call:

  String.format(format, date, source, logger, level, message, thrown);

  The first argument ‘format’ can be customized in the logging.properties or by a command line option or can be set programmatically. The good thing, we don’t have to learn new formatting specifiers here, as java.util.Formatter specification is fully supported.

  Using logging.properties

  Let’s add a new line to logging.properties with property key
  java.util.logging.SimpleFormatter.format to specify our desire log format.

  src/main/resources/logging.properties

  handlers= java.util.logging.ConsoleHandler .level= INFO java.util.logging.ConsoleHandler.level = INFO java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter java.util.logging.SimpleFormatter.format=[%1$tF %1$tT] [%4$-7s] %5$s %n 

  public class MyClass < private static Logger LOGGER = null; static < InputStream stream = MyClass.class.getClassLoader(). getResourceAsStream("logging.properties"); try < LogManager.getLogManager().readConfiguration(stream); LOGGER= Logger.getLogger(MyClass.class.getName()); >catch (IOException e) < e.printStackTrace(); >> public static void main(String[] args) < System.out.println("-- main method starts --"); LOGGER.info("in MyClass"); LOGGER.warning("a test warning"); >>

  Output

  -- main method starts --
  [2017-05-18 14:02:49] [INFO ] in MyClass 
  [2017-05-18 14:02:49] [WARNING] a test warning 
  

  Check this out to quickly learn different time formatting options

  Using system property

  public class MyClass2 < private static Logger LOGGER = null; static < System.setProperty("java.util.logging.SimpleFormatter.format", "[%1$tF %1$tT] [%4$-7s] %5$s %n"); LOGGER = Logger.getLogger(MyClass2.class.getName()); >public static void main(String[] args) < System.out.println("-- main method starts --"); LOGGER.info("in MyClass2"); LOGGER.warning("a test warning"); >>

  Output

  -- main method starts --
  [2017-05-18 14:03:41] [INFO ] in MyClass2 
  [2017-05-18 14:03:41] [WARNING] a test warning 
  

  Programmatically setting format

  Here we have to set our own ConsoleHandler with customized SimpleFormatter instead of customizing the default one.

  package com.logicbig.example; import java.util.Date; import java.util.logging.ConsoleHandler; import java.util.logging.LogRecord; import java.util.logging.Logger; import java.util.logging.SimpleFormatter; public class MyClass3 < private static Logger LOGGER = null; static < Logger mainLogger = Logger.getLogger("com.logicbig"); mainLogger.setUseParentHandlers(false); ConsoleHandler handler = new ConsoleHandler(); handler.setFormatter(new SimpleFormatter() < private static final String format = "[%1$tF %1$tT] [%2$-7s] %3$s %n"; @Override public synchronized String format(LogRecord lr) < return String.format(format, new Date(lr.getMillis()), lr.getLevel().getLocalizedName(), lr.getMessage() ); >>); mainLogger.addHandler(handler); LOGGER = Logger.getLogger(MyClass3.class.getName()); > public static void main(String[] args) < System.out.println("-- main method starts --"); LOGGER.info("in MyClass3"); LOGGER.warning("a test warning"); >>

  Output

  -- main method starts --
  [2017-05-18 14:04:07] [INFO ] in MyClass3 
  [2017-05-18 14:04:07] [WARNING] a test warning 
  

  Example Project

  Dependencies and Technologies Used:

  Источник

  Читайте также:  Css user select img