Logging in Java applications using Log4j

Log4J è una libreria Java sviluppata dalla Apache Software Foundation che consente di mettere a punto un ottimo sistema di logging per tenere sotto controllo il comportamento di una applicazione in fase di sviluppo, di test e infine di go-live del proprio software. E’ lo standard de facto per il logging delle applicazioni Java.

Perché Log4j?

La domanda che subito protrebbe balzare alla mente è: ma a che mi serve un framework per fare il logging? Non è molto più semplice mettere tutta una serie di System.out? La verità è che piazzare dei System.out è molto veloce, ma presenta dei svantaggi, che diventano evidenti (e nefasti) il giorno prima della messa in produzione.

Di solito infatti il log viene utilizzato in fase di sviluppo per analizzare il corretto funzionamento dell’applicazione. Quando la fase di sviluppo è terminata e l’applicazione viene rilasciata è opportuno monitorare esclusivamente gli eventi più gravi o più significativi. Avrei quindi bisogno di comandi di logging che possano essere flessibili, ovvero che scrivano quando voglio tracciare approfonditamente, ma che smettano di farlo quando non ne ho più bisogno, senza dover cancellare la relativa riga di codice.

Sarebbe inoltre utile poter configurare in modo semplice dove questi log vengono scritti: infatti un’altra necessità è che in fase di sviluppo i log vengano scritti in console, in quanto consultabili velocemente, in fase di test o produzione vorrei che venissero scritti in un file; vorrei anche che quel file non crescesse poi in modo smisurato, perché quando diventa un Gb non riesco più ad aprirlo neanche con un editor performante.

Con Log4j tutte le esigenze di cui sopra vengono coperte, semplicemente modificando un file di configurazione, quindi operando in un singolo punto all’interno del nostro progetto.

Concetti base

Log4j mette a disposizione una serie di entità che consentono di impostare in modo sofisticato il sistema di logging della propria applicazione.

Logger

Specifica cosa voglio tracciare (quali classi, package). Molto spesso viene utilizzato il Root Logger, ovvero un Logger che si trova al top della gerarchia di package. Utilizzandolo si decide che per la nostra applicazione è sufficiente uno solo Logger che traccerà tutto. E’ tuttavia possibile definire diversi Logger: posso ad esempio stabilire che il package it.cosenonjaviste.myproject.core (e tutto ciò che esso contiene, classi o altri package) sia tracciato sul Logger1, mentre il package it.cosenonjaviste.myproject.ext sia tracciato sul Logger2.

Al Logger sono associabili diversi livelli di logging, riportati con rank crescente:

Ci sono poi due ulteriori livelli speciali:

  • ALL – possiede il rank più basso, è inteso per abilitare tutto il logging
  • OFF – possiede il rank più alto, è inteso per disabilitare tutto il logging

Ad ogni messaggio di tracciatura viene poi associato un livello: di seguito mostriamo come ottenere il Logger Log4j e i printing methods associati ai vari livelli:

public class MyLog4J
{
   public static void main(String[] args)
   {
      Logger logger = Logger.getLogger(MyLog4J.class);

      // printing methods:
      logger.info("Hello World!");
      logger.debug("Hello World!");
      logger.warn("Hello World!"); 
      logger.error("Hello World!");
      logger.fatal("Hello World!")
   }
}

Come si vede al metodo getLogger viene passata la classe corrente: il metodo è uno shorthand per getLogger(clazz.getName()) e ritorna il primo Logger che fa match con la stringa passata come parametro. Nel caso in cui non ci siano corrispondenze viene ritornato il Root Logger.

Il messaggio viene scritto sugli Appender associati al Logger se e solo se il suo livello è maggiore o uguale al livello associato al Logger:

Logging Levels

Grazie al concetto di livello associato al Logger e a ciascun messaggio riesco ad ottenere la flessibilità di cui parlavamo: infatti potremmo prevedere log di livello DEBUG per tenere traccia di alcune informazioni utili durante lo sviluppo, come il valore di particolari variabili, e log di livello ERROR per tenere traccia di informazioni utili quando l’applicazione è in produzione. Nel momento in cui l’applicazione è pronta per il go-live basta soltanto modificare il livello di log (sostituire DEBUG con ERROR) nel file di configurazione e ottengo una riduzione dei messaggi di tracciatura scritti senza dover modificare i sorgenti.

Appender

Specifica dove voglio loggare (console, file di testo etc.). Log4j mette già a disposizione diversi Appender. I più utilizzati sono i seguenti:

  • ConsoleAppender che permette di scrivere sulla console dell’applicazione
  • FileAppender che permette di scrivere su file
  • RollingFileAppender che permette di scrivere su un file di testo definendone la lunghezza massima. Quando la lunghezza massima è raggiunta, il file è rinominato aggiungendo un numero progressivo al nome del file (rotazione del file di log)
  • DailyRollingFileAppender che permette di scrivere su un file di testo definendone un intervallo di tempo massimo. Quando il tempo scade, viene creato un altro file
  • SocketAppender che permette di scrivere su un socket utilizzando il protocollo TCP/IP
  • JMSAppender che permette di scrivere su una coda JMS
  • SMTPAppender che permette di inviare mail utilizzando il protocollo SMTP e JavaMail
  • JDBCAppender che consente di inviare i log ad un database, configurando le tabelle riceventi

Ciascun Appender naturalmente ha bisogno di alcuni parametri di configurazione specifici. Ad esempio, il FileAppender ha bisogno della directory e del nome del file di log sul quale scrivere, mentre l'SMTPAppender ha bisogno dell’indirizzo del server SMTP.

I file di log (generati tramite FileAppender e RollingFileAppender) possono essere consultati tramite Apache Chainsaw, un Log viewer GUI-based.

Layout

Specifica con che formato voglio loggare. Log4J mette a disposizione diverse tipologie di Layout predefinite. Le principali sono le seguenti:

  • SimpleLayout che produce stringhe di testo semplice
  • PatternLayout che produce stringhe di testo formattate secondo un pattern definito nel file di configurazione
  • HTMLLayout che produce un layout in formato HTML
  • XMLLayout che produce un layout in formato XML

Se il layout non viene specificato, log4j utilizza il SimpleLayout

Configurazione

Per configurare la libreria e utilizzarla in un’applicazione è necessario scrivere un file di properties. Il file di configurazioe può anche essere scritto in formato xml, formato consigliato anche dal team di sviluppo di Log4j.

#log4j.properties
#LOGGER
log4j.rootLogger=DEBUG, APPENDER_OUT, APPENDER_FILE
#APPENDER_OUT
log4j.appender.APPENDER_OUT=org.apache.log4j.ConsoleAppender
log4j.appender.APPENDER_OUT.layout=org.apache.log4j.PatternLayout
log4j.appender.APPENDER_OUT.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n
#APPENDER_FILE
log4j.appender.APPENDER_FILE=org.apache.log4j.RollingFileAppender
log4j.appender.APPENDER_FILE.File=mioLog.log
log4j.appender.APPENDER_FILE.MaxFileSize=100KB
log4j.appender.APPENDER_FILE.MaxBackupIndex=1
log4j.appender.APPENDER_FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.APPENDER_FILE.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %p [%C:%L] - %m%n

Ed ecco di seguito la versione XML (mooooolto più COOL, vedere il wiki Log4j per il formato XML):

< ?xml version="1.0" encoding="UTF-8" ?>
< !DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

  
    
            
    
  
 
    
    
        
    
      
    
  
  
  
    
    
  

Nell’esempio il Logger viene impostato con livello DEBUG e gli vengono associati due Appender: APPENDER_OUT e APPENDER_FILE. Ciascun Appender definisce un indirizzamento del flusso. Nell’esempio l’APPENDER_OUT è di tipo Console mentre l’APPENDER_FILE è di tipo RollingFile. Nel layout si specifica di scrivere:

  • %p : priorità dell’evento di LOG
  • %t : nome del thread che genera l’evento
  • %c : categoria
  • %m : messaggio passato dall’applicazione
  • %n : ritorno a capo

Nel Javadoc di PatternLayout trovate come comporre la pattern string per avere il layout desiderato.

Utilizzo di Log4j nell’applicazione

Ora che abbiamo scritto il file di configurazione, vediamo con un semplicissimo esempio come è possibile utilizzare log4j nella nostra applicazione.

public class MyLog4J
{
   public static void main(String[] args)
      {
      //load configuration File
      PropertyConfigurator.configure("myLog.properties");

      //load configuration File in XML format
      //DomConfigurator.configure("myLog.xml");
      
      //get Logger Instance
      Logger log = Logger.getLogger(MyLog4J.class);

      //writing some logs at different levels
      log.debug("Test Livello DEBUG");
      log.info("Test Livello INFO");
      log.warn("Test Livello WARNING");
      log.error("Test Livello ERROR");
      log.fatal("Test Livello FATAL");
      }
}

Mediante il metodo statico configure della classe PropertyConfigurator (della classe DomConfigurator per il file di configurazione in formato XML) viene caricato il file di configurazione. Quest’operazione deve essere fatta solo una volta all’avvio dell’applicazione e non è necessaria qualora il file venga chiamato con il nome di default log4j.properties, poiché Log4j si occupa automaticamente di invocare il metodo.

PropertyConfigurator (così come DomConfigurator) ha anche un overloading del metodo configure che consente di passare come secondo parametro un delay in millisecondi: Log4j creerà un thread che ogni delay millisecondi controllerà se il file di configurazione è cambiato e se sì caricherà e applicherà le nuove impostazioni.

Con il metodo statico getLogger della classe Logger otteniamo un’istanza della classe mediante la quale possiamo invocare uno dei metodi disponibili corrispondenti ai diversi livelli di log predefiniti.

In entrambi i casi Log4j utilizza il pattern Singleton per cui, se in vari punti della applicazione si invoca un Logger con lo stesso nome, si otterrà sempre la stessa istanza.

Ad esempio scrivendo:

Logger log1 = Logger.getLogger("myLog");
Logger log2 = Logger.getLogger("myLog");

otteniamo due variabili che puntano alla stessa istanza. Se eseguiamo l’esempio notiamo che sia sulla console, sia sul file di log, vengono stampate le 5 voci, perché il livello definito nel file di configurazione è DEBUG che si trova al gradino più basso della gerarchia. Se impostiamo il livello ad ERROR, ad esempio, noteremo come vengano stampati esclusivamente i messaggi di ERROR e FATAL.

In conclusione

Log4j è un framework potente e flessibile che copre tutte le esigenze di tracciatura che finora nella mia esperienza mi sono trovato ad avere. Consiglio di impostarlo in fase di setup del progetto, prima di cadere nella tentazione di scrivere il primo System.out :-).

Manuele Piastra

Sono uno Scrum Master e Project Manager i cui skill tecnici sono focalizzati al momento sullo sviluppo di applicazioni Java EE su IBM Websphere 7.0 utilizzando JSF (RichFaces), JPA (EclipseLink) ed EJB3. Presso OmniaGroup ricopro il ruolo di Training Manager: seleziono il personale tecnico, mi occupo della sua crescita formativa organizzando Corsi e Workshop sia interni che esterni, molti dei quali hanno visto me come docente. -

  • GhostWriter

    Perfetto nella sua semplicita’!

  • Pingback: ()

  • Alvaruccio2000

    Ottimo post, mi sarà molto utile

  • ProgrammoPerVivere

    Anche a me sembra fattibile, spero di mettere subito in pratica, grazie!

  • Droid

    Ho avuto qualche problema ad inizializzare log4j con DOMConfigurator e un file xml embeddato in un jar (non riusciva a caricare log4j.dtd) ma alla fine ho risolto con un EntityResolver customizzato.

    Grazie del mini tutorial, niente più System.out per me 😉

  • Anonimo

    Vorrei aggiungere che per migliorare le performance è preferibile scrivere:
    if(log.isDebugEnabled()) log.debug(“Messaggio…”);e non solo:log.debug(“Messaggio…”);
    Un ulteriore aumento delle prestazioni si ottiene definendo una costante da utilizzare poi nel codice come segue:
    private static final boolean DEBUG_ENABLED = log.isDebugEnabled();
    if (DEBUG_ENABLED)
    log.debug(“Messaggio…”);

    Ciao e complimenti per l’articolo.

    • Grazie mille per i complimenti e le precisazioni correttissime!

  • Pingback: ()

  • Luca

    ciao a tutti..
    ho una domanda: è possibile far creare un log file, definito nel file di properties di log4j, in un secondo momento?

    • Ciao, per secondo momento intendi non all’avvio dell’applicazione ma per esempio al primo utilizzo? Che io sappia no, però potresti provare a guardare il codice del RollingFileAppender per farne uno adatto al caso tuo!