PV168/Logování

Obsah

1 Přehled
2 Logovací rozhraní
- 2.1 Simple Logging Facade for Java (SLF4J) [1]
  - 2.1.1 Live template pro SLF4J v IntelliJ IDEA
- 2.2 Jakarta Commons Logging (JCL) [2]
3 Implementace logování

Přehled

Logování je ukládání záznamů o činnosti programu, především o událostech, které signalizují nějaký problém. Účelem je v případě potřeby zpětné dohledání činnosti systému a/nebo diagnostikování chyby.

Triviálním systémem na logování je i použití System.err.println. Nevýhod tohoto přístupu je více:

Celou zaznamenávanou zprávu o události musíme sestavit sami -- většinou chceme poznačit alespoň čas/datum, místo vzniku události (např. třídu, balík, metodu) a její popis, případně i vlákno, v němž se to odehrálo.
Nelze jednoduše zařídit zapínání/vypínání logování. Např. v produkčním systému nás zajímají pouze skutečné chyby a nikoli ladicí informace, zatímco při vývoji a testování programu chceme vidět všechno.
Nelze snadno přesměrovat logovací výstupy, kam potřebujeme, tzn. např. do souboru, poslání mailem, do databáze, do /dev/null.
Nelze snadno regulovat logování v některých částech programu, např. v některých třídách povolit podrobnější úroveň sledování než v jiných (např. tam, kde víme, že fungují OK).

Drtivá většina systémů pro logování má dvě části, architekturní komponenty:

Rozhraní, využívané programem, z něhož logujeme, a
Implementaci, která realizuje vlastní sestavování zpráv a jejich odesílání na správné místo.

Rozhraní

Aby nemusely být aplikace a knihovny psány pro konkrétní z těchto implementací, existují dvě obalovací logovací knihovny, které neposkytují implementaci logování, jen rozhraní:

Simple Logging Facade for Java (SLF4J) http://www.slf4j.org/
Jakarta Commons Logging (JCL) http://commons.apache.org/logging/

SLF4J je nástupce JCL, odstraňuje jeho problémy s classloadery.

Implementace

V jazyce Java existují v podstatě tyto tři hlavní implementace logování:

JUL (java.util.logging) Java Logging Overview -- tato jediné je součástí Java Core API, ostatní se musí instalovat/přidávat:
Logback http://logback.qos.ch/ (t.č. pravděpodobně nejšikovnější implementace logování)
Log4j 2 http://logging.apache.org/log4j/2.x/ (kdysi populární, dnes na pomalém ústupu a nahrazováno Logback)

Logback a Log4J jsou od stejného autora, Logback je novější, rychlejší a flexibilnější než Log4J. Log4J bylo odjakživa lepší než JUL, ale JUL byl prosazen silou firmou Sun jako standardní součást JDK.

Co mám použít ?

Ve zdrojových textech svých programů používejte jako rozhraní SLF4J.

Při nasazení programů používejte implementaci Logback, v jednoduchém testovacím prostředí můžete pro SLF4J použít jeho implementaci "simple", např. slf4j-simple-1.7.21.jar.

Při využití cizích knihoven nebo programů, které používají něco jiného, využijte SLF4J legacy bridge, tj. jcl-over-slf4j, log4j-over-slf4j, jul-to-slf4j bridge.

Spring Boot Starter Logging

Nejjednodušší je do svého projektu přidat tzv. Spring Boot Starter Logging, který přidá SLF4J, Logback a všechny SLF4J legacy bridges. Do pom.xml stačí přidat

 
       <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-logging</artifactId>
            <version>2.1.3.RELEASE</version>
       </dependency>

Logovací rozhraní

Simple Logging Facade for Java (SLF4J) [1]

náhrada za nepodařené JCL
diskuze o SLF4J na The ServerSide

Definuje úrovně ALL, TRACE, DEBUG, INFO, WARN, ERROR, FATAL, OFF, viz třída Level.

Použití

 
public class PbsCacheImpl implements PbsCache {
 
    final static Logger log = LoggerFactory.getLogger(PbsCacheImpl.class);
 //...
 
  // u jednoduchých výpisů stačí uvést řetězec a argumenty pro nahrazení
  log.debug("Server {} má {} položek",server,numItems);
 
  //u složitějších výpisů je vhodné předřadit if, aby se argumenty zbytečně nevyhodnocovaly
  if(log.isDebugEnabled()) {
     log.debug("Měla "+babka+" "+babkaPocetJablek+" a dědoušek jen "+dedaPocetJablek);
  }
 
  // u vyjímek pak
   try {
     //...
   } catch(Exception ex) {
     log.error("Houstone, máme problém",ex);
   }

Pokud používáte projekt typu Maven, přidáte knihovnu SLF4J rozhraní přidáním této závislosti:

 
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.25</version>
</dependency>

nebo u spustitelného projektu se můžete spolehnout na to, že tranzitivními závislostmi bude SLF4J přidán automaticky, např. přidáním Logback:

 
<dependency> 
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-classic</artifactId>
  <version>1.2.3</version>
</dependency>

Live template pro SLF4J v IntelliJ IDEA

V IntelliJ IDEA existují zkratky, tzv. Live Templates. Je výhodné si nastavit zkratku pro vkládání deklarace proměnné pro logování, viz následující obrázek, pak lze deklaraci vložit posloupností kláves slf<Enter>.

Jakarta Commons Logging (JCL) [2]

U nových projektů není doporučeno používat.

problémy při použití rozdílných knihoven (class loader problems)
memory leaks
o nevýhodách Commons Logging
true story about JCL
JCL no more!

Implementace logování

Logback [3]

nástupce Log4J od stejného autora
výhody Logback proti Log4J
logback-classic přímo implementuje rozhraní SLF4J, které doporučuje používat

V projektech typu Maven stačí přidat závislost:

 
  <dependency>
   <groupId>ch.qos.logback</groupId>
   <artifactId>logback-classic</artifactId>
   <version>1.2.3</version>
  </dependency>

Pokud neexistuje konfigurační soubor, automaticky loguje všechno od úrovně DEBUG na standardní výstup.

Konfigurační soubor definuje

appender - kam a jakým způsobem se budou logy ukládat, např. na konzolu, do denně rotovaného souboru, do syslogu, do SQL databáze, atd.
logger - má jméno a úroveň, určuje od jaké Level (DEBUG, INFO atd.) budou události v určitých třídách nebo packages logovány.
root - definuje hlavní appender a úroveň, kterou od něj dědí explicitně nevyjmenované loggery

Nejjednodušší konfigurační soubor vypadá takto:

 
<configuration>
    <appender name="APP" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>
    
    <root level="info">
        <appender-ref ref="APP"/>
    </root>
 
    <logger name="cz" level="warn"/>
    <logger name="cz.muni.fi.pv168" level="info"/>
    <logger name="cz.muni.fi.pv168.cemetery.GraveManagerImpl" level="debug"/>
 
</configuration>

Složitější následující soubor logback.xml určuje, že

variantní appendery:
- pokud budou třídy uvnitř servletového kontejneru Tomcat, bude se logovat do denně rotovaného souboru s názvem obsahujícím datum, např. mujprojekt.log.2013-12-31
- pokud nebudou třídy v Tomcatu, bude se logovat na konzolu (standardní výstup)
loggery pro různé packages a třídy
- třída cz.muni.fi.pv168.cemetery.GraveManagerImpl bude logovat na úrovni DEBUG
- ostatní třídy jejichž balík začíná na cz.muni.fi.pv168 budou logovat na úrovni INFO
- ostatní třídy jejichž balík začíná na cz budou logovat na úrovni WARN
tzv. root logger, ze kterého dědí nevyjmenované loggery, loguje od úrovně INFO

 
<configuration>
    <contextName>mujprojekt</contextName>
 
    <if condition='isDefined("catalina.base")'>
        <then>
            <appender name="APP" class="ch.qos.logback.core.rolling.RollingFileAppender">
                <file>${catalina.base}/logs/${CONTEXT_NAME}.log</file>
                <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
                    <fileNamePattern>${catalina.base}/logs/${CONTEXT_NAME}.log.%d{yyyy-MM-dd}</fileNamePattern>
                </rollingPolicy>
                <encoder>
                    <!-- http://logback.qos.ch/manual/layouts.html#conversionWord -->
                    <pattern>%d [%thread] %-5level %logger{36} - %msg%n</pattern>
                </encoder>
            </appender>
        </then>
        <else>
            <appender name="APP" class="ch.qos.logback.core.ConsoleAppender">
                <encoder>
                    <pattern>%d [%thread] %-5level %logger{36} - %msg%n</pattern>
                </encoder>
            </appender>
        </else>
    </if>
 
    <logger name="cz" level="warn"/>
    <logger name="cz.muni.fi.pv168" level="info"/>
    <logger name="cz.muni.fi.pv168.cemetery.GraveManagerImpl" level="debug"/>
 
    <root level="info">
        <appender-ref ref="APP"/>
    </root>
 
</configuration>

Pokud používáme v konfiguračním souboru variany pomocí tagů <if><then<else>, je třeba ještě přidat knihovnu Janino, tedy závislost

 
   <dependency>
     <groupId>org.codehaus.janino</groupId>
     <artifactId>janino</artifactId>
     <version>2.6.1</version>
   </dependency>

Pokud používáme kromě vlastního kódu i knihovny, které používají některý jiný logovací framework, tj. JCL nebo Log4J, přesměrujeme jejich logovací výpisy do SLF4J a tím do Logback přidáním závislostí

 
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>jcl-over-slf4j</artifactId>
            <version>1.7.2</version>
        </dependency>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>log4j-over-slf4j</artifactId>
            <version>1.7.2</version>
        </dependency>

Log4j2 (LS) [4]

velmi komplexní a robustní logovací knihovna
umí vše co JUL a něco navíc
defacto standard logování J2EE aplikací
nyní součástí http://logging.apache.org/
úrovně (třída Level) ALL, TRACE, DEBUG, INFO, WARN, ERROR, FATAL, OFF
handlery pro logování na konzolu, do souboru, do databáze, přes JMS, do syslogu, emailem a další

Pro správnou funkci je třeba mít v CLASSPATH soubor jménem log4j2.xml s konfigurací, např.:

 
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug" strict="true" name="XMLConfigTest" packages="">
    <Appenders>
        <!-- appender určuje, kam se bude logovat, v tomto případě na konzolu -->
        <Console name="STDOUT" target="SYSTEM_OUT">
            <PatternLayout pattern="%d [%t] %-5p %c - %m%n"/>
        </Console>
        <!-- tento appender loguje do denně rotovaného souboru v adresáři určeném obsahem systémové property catalina.base-->
        <RollingFile name="RollingFile" fileName="${catalina.base}/logs/app.log" filePattern="${catalina.base}/logs/app-%d{MM-dd-yyyy}-%i.log">
            <PatternLayout>
                <Pattern>%d [%t] %-5p %c - %m%n</Pattern>
            </PatternLayout>
            <Policies>
               <TimeBasedTriggeringPolicy />
               <SizeBasedTriggeringPolicy size="250 MB"/>
            </Policies>
        </RollingFile>
    </Appenders>
    <!-- definuje hlavní konfiguraci, tedy které z appenderů se mají použít -->
    <Loggers>
        <!-- určuje úroveň logování pro třídy v určitém package -->
        <Logger name="net.sourceforge.stripes" level="trace">
            <AppenderRef ref="STDOUT"/>
        </Logger>
        <!-- všechno ostatní se bude logovat s defaultně nastavenou úrovní -->
        <Root level="error">
	    <AppenderRef ref="STDOUT" />
            <AppenderRef ref="RollingFile" />
        </Root>
    </Loggers>
</Configuration>

Rovněž je možné konfiguraci dodat ve formátu JSON nebo jako .properties soubor.

java.util.logging (JUL) [5]

ve standardním API od JDK 1.4
třída Logger (instance mají asociované jméno, jehož základ by měl tvořit název balíku, protože je na něm postavena hierarchie Loggerů)
Úrovně (instance třídy Level) ALL, FINEST, FINER, FINE, CONFIG, INFO, WARNING, SEVERE, OFF
Možnost implementace vlastního Filteru
Připravené handlery pro paměť, OutputStream, soubor (včetně rotování), konzolu, IP socket (i více najednou)
Připravené textové a XML formátování
Podpora lokalizovaných zpráv přebíraných z ResourceBundle
LogManager spravující všechny Loggery a jejich konfiguraci

Když neprovedu žádnou konfiguraci, JUL loguje od úrovně INFO na konzolu pomocí SimpleFormatter, protože to je konfigurace v souboru $JAVA_HOME/lib/logging.properties.

Pokud to chci změnit, musím vyrobit soubor logging.properties s obsahem alespoň

#vypis pujde na konzolu
handlers=java.util.logging.ConsoleHandler
# handler propusti vsechno od finest
java.util.logging.ConsoleHandler.level=FINEST
# loggery propusti vsechno od finest
.level= FINEST
#
#java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter
#java.util.logging.ConsoleHandler.formatter=java.util.logging.XMLFormatter

a při spuštění specifikovat jeho místo:

java -Djava.util.logging.config.file=/home/nekdo/nekde/logging.properties