Loggning: vad, hur, var och med vad?

Hej alla i CodeGym-communityt! Idag ska vi prata om loggning:

1. Vad det är, varför det finns, när du bör använda det, när du bör undvika det.
2. Vilka loggningsimplementeringar finns tillgängliga i Java, och vad du bör göra med alla dessa loggningsalternativ.
Och loggnivåer. Vi kommer att diskutera vad appender är och hur man konfigurerar den korrekt.
3. Logga noder och hur man konfigurerar dem korrekt så att allt fungerar som vi vill.

Detta material är avsett för en bred publik. Det kommer att vara tydligt för alla som bara lär känna Java, såväl som för personer som redan arbetar men bara har utforskat logger.info("log something"); Let's go!

Varför behöver du loggning?

Låt oss titta på några verkliga fall där loggning kan lösa ett problem. Här är ett exempel från mitt arbete. Det finns punkter där en applikation integreras med andra tjänster. Jag använder loggning vid dessa punkter för att etablera ett slags "alibi" : om integrationen inte fungerar blir det lätt att ta reda på vilken sida som har problemet. Det är också önskvärt att logga viktig information lagrad i en databas. Till exempel skapandet av en administratörsanvändare. Det är precis sånt som skulle vara bra att logga.

Verktyg för att logga in i Java

Bland de välkända loggningslösningarna i Java kan vi lyfta fram följande:

• Log4j
• JUL — java.util.logging
• JCL — Jakarta Commons Logging
• Logga tillbaka
• SLF4J — Enkel loggningsfasad för Java

System.err.println

I början fanns System.err.println (visar loggposter på konsolen). Än idag används denna teknik för att snabbt logga vid felsökning. Naturligtvis finns det inga inställningar att diskutera här, så kom bara ihåg den här metoden så går vi vidare.

Log4j

Detta är en komplett lösning som utvecklare skapat av nödvändighet. Resultatet är ett riktigt intressant verktyg som du kan använda. På grund av olika omständigheter hamnade denna lösning inte i JDK, ett faktum som upprörde hela samhället kraftigt. Log4j har konfigurationsalternativ som låter dig aktivera inloggning av com.example.typepaketet och stänga av det i com.example.type.genericunderpaketet. Detta gör det möjligt att snabbt utesluta kod som inte behöver loggas. Det är viktigt att notera här att det finns två versioner av Log4j: 1.2.x och 2.xx, och de är inkompatibla med varandra . Log4j lade till begreppen appender(ett verktyg som används för att skriva loggar) och layout (loggformatering). Detta låter dig logga bara det du behöver och logga det precis som du behöver det. Vi kommer att prata mer om appender lite senare.

JUL — java.util.logging

En av de viktigaste fördelarna med denna lösning är att JUL ingår i JDK (Java Development Kit). Tyvärr, när det utvecklades, baserade dess skapare det inte på det populära Log4j-verktyget, utan snarare en lösning från IBM. Det beslutet har fått konsekvenser. Verkligheten är att ingen använder JUL nu. Loggnivåerna i JUL skiljer sig från vad Logback, Log4j och Slf4j har. Detta gör det svårare för dem att förstå varandra. Att skapa en logger är mer eller mindre liknande. För att göra detta måste du göra en import:

java.util.logging.Logger log = java.util.logging.Logger.getLogger(LoggingJul.class.getName());

Klassnamnet är godkänt, så vi vet var vår loggning kommer ifrån. Från och med Java 8 kan du klara Supplier<String>. Detta hjälper oss att läsa och skapa en rad bara när vi verkligen behöver den, snarare än varje gång, som tidigare. Först med utgivningen av Java 8 löste utvecklarna äntligen viktiga problem och gjorde JUL verkligen användbar. Nämligen metoder med en Supplier<String> msgSupplierparameter, som visas nedan:

public void info(Supplier<String> msgSupplier) {
   log(Level.INFO, msgSupplier);
}

JCL — Jakarta Commons Logging

Eftersom det inte funnits någon branschstandard för loggning på länge och många människor skapade sina egna anpassade loggare, togs beslutet att släppa JCL, ett allmänt omslag som kunde användas ovanpå andra. Varför? Ibland använde beroenden som lagts till projektet en annan logger än den i projektet. På grund av detta lades de till projektet som transitiva beroenden, och detta skapade verkliga problem när man försökte få ihop allt. Tyvärr var omslaget inte särskilt funktionellt och tillförde ingenting. Det skulle nog vara bekvämt om alla använde JCL. Men det var inte vad som hände, så att använda JCL är inte den bästa idén för tillfället.

Logga tillbaka

Sökvägen med öppen källkod är svår... Samma utvecklare som skrev Log4j skrev också Logback som ett efterföljande loggningsramverk. Det baserades på samma idé som Log4j. Skillnaderna i inloggning är:

• förbättrad prestanda
• lagt till inbyggt stöd för Slf4j
• utökade filtreringsalternativ

Som standard kräver Logback ingen konfiguration och registrerar alla händelser på DEBUG-nivå och högre. Om du behöver lite anpassning kan du få det genom en XML-konfiguration:

<configuration> 
    <appender name="FILE" class="ch.qos.logback.core.FileAppender"> 
        <file>app.log</file> 
        <encoder> 
            <pattern>%d{HH:mm:ss,SSS} %-5p [%c] - %m%n</pattern> 
        </encoder> 
    </appender> 
    <logger name="org.hibernate.SQL" level="DEBUG" /> 
    <logger name="org.hibernate.type.descriptor.sql" level="TRACE" /> 
    <root level="info"> 
        <appender-ref ref="FILE" /> 
    </root> 
</configuration>

SLF4J — Enkel loggningsfasad för Java

Någon gång under 2006 lämnade en av Log4js grundare projektet och skapade Slf4j (Simple Logging Facade for Java), ett omslag för Log4j, JUL, common-logging och Logback. Som du kan se har vi avancerat till punkten att skapa ett omslag över ett omslag... I det här fallet är det uppdelat i två delar: ett API som används i applikationen och en implementering som läggs till med separata beroenden för varje typ av loggning. Till exempel slf4j-log4j12.jaroch slf4j-jdk14.jar. Du måste koppla upp den korrekta implementeringen och det är allt: hela ditt projekt kommer att använda den. Slf4j stöder alla de senaste funktionerna, som att formatera strängar för loggning. Tidigare fanns ett sådant problem. Låt oss säga att vi skapar en loggpost så här:

log.debug("User " + user + " connected from " + request.getRemoteAddr());

På grund av sammanlänkningsoperatorn userblir objektet tyst en sträng tack vare user.toString(). Detta tar tid och saktar ner systemet. Och det kan vara OK om vi felsöker programmet. Vi börjar stöta på problem om loggnivån för denna klass är INFO eller högre. Med andra ord, vi bör inte skriva denna loggpost (för INFO eller högre), och vi bör inte använda strängsammansättning. I teorin borde loggningsbiblioteket självt ta itu med detta. Detta visade sig vara det största problemet i den första versionen av Log4j. Det gav ingen anständig lösning, men föreslog istället att man skulle göra något så här:

if (log.isDebugEnabled()) {
    log.debug("User " + user + " connected from " + request.getRemoteAddr());
}

Det vill säga, istället för en rad kod för loggning föreslog de att skriva 3! Loggning bör minimera kodändringar, och de tre raderna bryter tydligt mot den allmänna strategin. Slf4j hade inga kompatibilitetsproblem med JDK och API, så en trevlig lösning dök upp omedelbart:

log.debug("User {} connected from {}", user, request.getRemoteAddr());

där {}betecknar platshållare för argumenten som skickas till metoden. Det vill säga, den första {}motsvarar user, och den andra {}motsvarar request.getRemoteAddr(). Genom att göra det på detta sätt kommer vi att utföra strängsammansättning endast om loggnivån kräver att vi skriver loggposten. Därefter började Sjf4j snabbt växa i popularitet. I dagsläget är det den bästa lösningen. Låt oss därför ta en titt på loggning med en slf4j-log4j12bindning.

Vad behöver loggas

Självklart ska du inte logga allt. Detta är ofta inte nödvändigt och ibland till och med farligt. Till exempel, om du loggar någons personliga data och det på något sätt läcker ut, kommer det att finnas verkliga problem, särskilt i projekt fokuserade på västerländska marknader. Men det finns också saker som du definitivt bör logga :

1. Start/slut på ansökan. Vi måste veta om ansökan verkligen började och slutade som förväntat.
2. Säkerhetsproblem. Här skulle det vara bra att logga försök att gissa någons lösenord, tillfällen när administratörer loggar in osv.
3. Vissa tillämpningsstater . Till exempel övergången från ett tillstånd till ett annat i en affärsprocess.
4. Viss felsökningsinformation tillsammans med motsvarande loggnivå.
5. Vissa SQL-skript. Det finns fall i verkliga världen när detta är nödvändigt. Men återigen, genom att skickligt justera loggnivåerna kan du uppnå utmärkta resultat.
6. Pågående trådar kan loggas när man verifierar att saker fungerar korrekt.

Populära fel i loggning

Det finns många nyanser här, men vi kommer att särskilt nämna några vanliga misstag:

1. Överdriven loggning. Du bör inte logga alla steg som teoretiskt sett kan vara viktiga. Här en bra tumregel: Loggar bör inte överstiga 10% av belastningen. Annars kommer det att uppstå prestandaproblem.
2. Loggar all data till en fil. Vid något tillfälle kommer detta att göra det mycket svårt att läsa/skriva loggen, för att inte tala om det faktum att vissa system har begränsningar för filstorlek.
3. Använder felaktiga loggnivåer. Varje stocknivå har tydliga gränser, och de bör respekteras. Om en gräns är otydlig kan man komma överens om vilken nivå som ska användas.

Logga nivåer

Vad är loggnivåer? För att på något sätt skapa en hierarki av loggposter krävs vissa konventioner och avgränsningar. Det är därför loggnivåer infördes. Nivån ställs in i applikationen. Om en post är under en angiven nivå loggas den inte. Vi har till exempel loggar som vi använder vid felsökning av applikationen. Under normal drift (när applikationen används för sitt avsedda syfte) behövs inte sådana loggar. Därför är loggnivån högre än för felsökning. Låt oss titta på loggnivåer med Log4j. Förutom JUL använder andra lösningar samma loggnivåer. Här är de i fallande ordning:

• AV: Inga loggposter registreras; allt ignoreras.
• FATAL: Ett fel som hindrar programmet från att fortsätta att köras. Till exempel, "JVM slut på minnesfel".
• FEL: Fel på denna nivå indikerar problem som måste lösas. Felet stoppar inte programmet som helhet. Andra förfrågningar kan fungera korrekt.
• VARNING: Loggposter som representerar en varning. Något oväntat hände, men systemet kunde hantera och uppfyllde begäran
• INFO: Loggposter som indikerar viktiga åtgärder i applikationen. Dessa är inte fel eller varningar. De är förväntade systemhändelser.
• DEBUG: Loggposter måste felsöka programmet. För att säkerställa att applikationen gör exakt vad som förväntas, eller för att beskriva de åtgärder som applikationen vidtagit, det vill säga "Entered method1".
• TRACE: Loggposter med lägre prioritet för felsökning. Den lägsta loggnivån.
• ALLA: En loggnivå för att skriva alla programmets loggposter.

I INFO-loggnivån är aktiverad någonstans i applikationen, då kommer posterna för varje nivå att loggas, från INFO till FATAL. Om FATAL-loggnivån är inställd kommer endast loggposter med den nivån att skrivas.

Logga och skicka loggar: Bilaga

Låt oss överväga hur allt detta fungerar när vi använder Log4j, vilket ger stora möjligheter att skriva/skicka loggar:

• att skriva till en fil —DailyRollingFileAppender
• att skriva information till konsolen —ConsoleAppender
• att skriva loggar till en databas —JDBCAppender
• för att hantera sändningsloggar över TCP/IP —TelnetAppender
• för att säkerställa att loggning inte påverkar prestandan negativt —AsyncAppender

Det finns några fler implementeringar: en komplett lista finns tillgänglig här . Förresten, om bilagan du behöver inte finns är det inga problem. Du kan skriva din egen appender genom att implementera Appender- gränssnittet, som Log4j stöder.

Loggningsnoder

För demonstrationsändamål kommer vi att använda ett Slf4j-gränssnitt, med en implementering från Log4j. Att skapa en logger är väldigt enkelt: i en klass som heter , MainDemosom kommer att göra en del loggning, måste vi lägga till följande:

org.slf4j.Logger logger = org.slf4j.LoggerFactory.getLogger(MainDemo.class);

Detta kommer att skapa en logger för oss. För att göra en loggpost finns det flera tillgängliga metoder vars namn speglar vilken loggnivå som kommer att användas. Till exempel:

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 the log4j.properties file. Please fix this.");
logger.error("Connection refused to host = {}", host);

Även om vi klarar klassen är det slutliga namnet klassens fullständiga namn, inklusive paket. Detta görs så att du senare kan dela upp loggningen i noder och konfigurera loggningsnivån och bilagan för varje nod. Loggaren skapades till exempel i com.github.romankh3.logginglecture.MainDemoklassen. Namnet utgör grunden för att skapa en hierarki av loggningsnoder. Huvudnoden är RootLogger på toppnivå . Detta är noden som tar emot alla loggposter för hela applikationen. De återstående noderna kan avbildas enligt nedan: Appendrar är konfigurerade för specifika loggningsnoder. Nu ska vi titta på log4j.properties- filen för att se ett exempel på hur man konfigurerar dem.

En steg-för-steg-guide till filen log4j.properties

Vi ställer in allt ett steg i taget och ser vad som är möjligt:

log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender

Den här raden säger att vi registrerar CONSOLE-appendern, som använder implementeringen org.apache.log4j.ConsoleAppender. Denna appendator skriver information till konsolen. Därefter registrerar vi en annan appendator. Den här kommer att skriva till en fil:

log4j.appender.FILE=org.apache.log4j.RollingFileAppender

Det är viktigt att notera att själva tilläggen fortfarande måste konfigureras. När vi har registrerat våra appendrar kan vi bestämma vilka loggnivåer och vilka appendrar som ska användas vid noderna.

log4j.rootLogger=DEBUG, KONSOL, FIL

• log4j.rootLogger betyder att vi konfigurerar rotnoden, som innehåller alla loggposter
• Det första ordet efter likhetstecknet indikerar den lägsta loggnivån att skriva (i vårt fall är det DEBUG)
• Efter kommatecken anger vi alla bilagor som ska användas.

För att konfigurera en mer specifik loggningsnod skulle du använda en post så här:

log4j.logger.com.github.romankh3.logginglecture=TRACE, OWN, CONSOLE

där log4j.logger.används för att referera till en specifik nod. I vårt fall, com.github.romankh3.logginglecture. låt oss nu prata om att konfigurera CONSOLE-appendern:

# CONSOLE appender customization
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

Här ser vi att det är möjligt att ställa in den specifika nivån på vilken appendaren ska börja fungera. Här är ett exempel på vad som faktiskt händer: anta att ett meddelande med INFO-nivån tas emot av loggningsnoden och skickas till den appendator som tilldelats den. Om appendarens tröskel är inställd på WARN, tar den emot loggposten men gör ingenting med den. Därefter måste vi bestämma vilken layout meddelandet ska använda. Jag använder PatternLayout i exemplet, men det finns många andra alternativ. Vi kommer inte att täcka dem i den här artikeln. Exempel på konfiguration av FILE-appendern:

# File appender customization
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

Du kan konfigurera den specifika filen till vilken loggposter kommer att skrivas, som kan ses på denna rad:

log4j.appender.FILE.File=./target/logging/logging.log

Posten skrivs till logging.logfilen. För att undvika problem med filstorleken kan du konfigurera den maximala, som i det här fallet är 1 MB. MaxBackupIndexanger hur många sådana loggfiler det kommer att finnas. Om vi ​​behöver skapa fler filer än så här kommer den första filen att raderas. För att titta på ett verkligt exempel där loggning är konfigurerad kan du gå till det offentliga arkivet på GitHub.

Förstärk det vi har diskuterat

Försök på egen hand att göra allt vi har beskrivit:

• Skapa ditt eget projekt som liknar vårt exempel ovan.
• Om du vet hur man använder Maven, använd den. Om inte, läs den här handledningen, som beskriver hur du ansluter biblioteket.

Sammanfattningsvis

1. Vi pratade om loggningslösningarna som finns i Java.
2. Nästan alla välkända loggningsbibliotek skrevs av en person :D
3. Vi lärde oss vad som bör och inte bör loggas.
4. Vi räknade ut loggnivåer.
5. Vi introducerades till loggningsnoder.
6. Vi tittade på vad en appender är och vad den är till för.
7. Vi skapade en log4j.proterties-fil steg för steg.

Ytterligare material

1. CodeGym: Loggerlektion
2. Weekly Geekly: Java-loggning. Hej världen
3. Kodningsskräck: problemet med loggning
4. YouTube: Understanding Java Logging Hell - Grunderna. Java Logging Hell & Hur man håller sig utanför det
5. Log4j: Appender
6. Log4j: Layout

Se även min andra artikel:

• Felsökning i IntelliJ IDEA: en nybörjarguide