Il tema di “far scrivere dei messaggi significativi alle nostre applicazioni” penso sia noto a tutti tuttavia occorre capire se quello che scriviamo ha un senso ed una logica e come possiamo pilotare gli strumenti in nostro possesso per farli diventare una potente arma nelle nostre mani.
Mi è capitato spessissimo di trovare le solite “System.out.println” all’interno di svariate classi pagate a peso d’oro all’ennesima ditta di fornitori o comunque di trovare “log.info” o “log.debug” usati in maniera indistinta per segnalare qualunque tipo di messaggio/errore.
Ad oggi possiamo parlare di 4 framework principali per il logging in ambiente java: Log4j, Java Logging API, Apache Commons Logging e SLF4J.
A mio avviso il framework di riferimento rimane comunque log4j ed è su questo che ci concentreremo.
Assumo che il tema sia abbastanza noto, quindi volendo sintetizzare per i ritardatari:
- Appender. Sono gli oggetti che mi permettono di definire una destinazione per i miei log, può essere lo standard output, un file su disco, un socket o altro ancora.
- Logger. Sono gli oggetti grazie ai quali posso scrivere su una delle destinazioni. Un Logger si può associare ad una classe specifica o a tutte le classi di un package.
- Level. Sono i valori di logging che possiamo assegnare ad un particolare messaggio tenendo conto che vale la seguente relazione: TRACE < DEBUG < INFO < WARN < ERROR < FATAL. Trace è la modalità di logging più verbosa che possiamo attivare mentre fatal ci permette di intercettare esclusivamente dei problemi “bloccanti”.
Quando usare un livello rispetto ad un altro? Questo tipicamente dipende dall’applicazione ma in generale la regola è la seguente:
- Debug, per la fase di test e successivamente per permetterci di individuare problemi che si possano presentare una volta che il sistema è in produzione.
- Info, per tracciare le informazioni di base atte a indicare che la nostra applicazione è Up&Running.
- Warning, per tracciare quelle informazioni che può essere utile sapere perchè in contrasto con le regole generali dell’applicazione ma che non hanno particolari impatti.
- Error, per tracciare gli errori importanti che è bene segnalare e che tipicamente vanno interpretati e corretti e comunque gestiti al meglio.
- Fatal, per indicare delle problematiche bloccanti che non permettono la corretta esecuzione della nostra applicazione.
Facciamo un esempio in pseudo-codice:
try {
log.info(“Attivazione connessione socket”);
log.debug(“URL connessione: ”+url);
log.debug(“User: ”+user);
log.debug(“Password: ”+password);
socket.connect(url, user, password);
socket.send(data);
catch(SocketException se) {
log.fatal(“impossibile stabilire una connessione”);
}
catch(AuthenticationException ae) {
log.error(“Utente o password errati. Verrà attivata una sessione guest con minori privilegi”);
}
catch(DataValidationException dve) {
log.warn(“Il buffer dati ha una lunghezza inferiore a quella attesa.”);
}
Fin qui penso di non aver dato nessun contributo significativo.
Vediamo ora una configurazione interessante che si può utilizzare per tenere sotto controllo le nostre applicazioni.
Supponiamo di avere un’applicazione con 3 classi alle quali siamo principalmente interessati chiamate rispettivamente LoggerTestA, LoggerTestB e LoggerTestC.
Immaginando di rilasciare in produzione la nostra applicazione, potrebbe essere utile tenere il logging in debug almeno per un pò in modo da avere tutti i log del caso qualora questo fosse necessario quindi predisporremo un rolling log che ci permette di tracciare i log verbosi senza preoccuparci di andare a saturare per disgrazia lo spazio disco del nostro server.
In aggiunta andremo a scrivere il normale logging di INFO sullo standard output e poichè siamo particolarmente interessati ai WARNING scatenati dalla classe LoggerTestB, le riserviamo un ulteriore file di log dedicato.
>> Note: idealmente i log in debug non andrebbero mai messi su un sistema in produzione ma nel mondo reale questa è una prassi che si trova abbastanza di frequente... NON dite di no sapendo di mentire!
# APPENDER
# STDOUT in info
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
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
# FILE CUSTOM in warning
log4j.appender.custom=org.apache.log4j.FileAppender
log4j.appender.custom.File=log/custom.log
log4j.appender.custom.layout=org.apache.log4j.PatternLayout
log4j.appender.custom.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %5p %c{1}:%L - %m%n
# ROLLING FILE in debug
log4j.appender.roll=org.apache.log4j.RollingFileAppender
log4j.appender.roll.File=log/roll.log
log4j.appender.roll.MaxFileSize=100KB
log4j.appender.roll.MaxBackupIndex=3
log4j.appender.roll.layout=org.apache.log4j.PatternLayout
log4j.appender.roll.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %5p %c{1}:%L - %m%n
# LOGGER
log4j.rootLogger=INFO, stdout
log4j.logger.it.lcianci.test.log4j.LoggerTestB=WARN, custom
log4j.logger.it.lcianci.test.log4j.LoggerTestA=DEBUG, roll
log4j.logger.it.lcianci.test.log4j.LoggerTestB=DEBUG, roll
log4j.logger.it.lcianci.test.log4j.LoggerTestC=DEBUG, roll
Questo tipo di configurazione, ovvero mediante il file log4j.properties, avviene mediante l’utilizzo della classe PropertyConfigurator da qualche parte nella fase di startup della nostra applicazione:
PropertyConfigurator.configure("conf/log4j.properties");
Ecco quindi uno stralcio dei nostri log:
Standard output
2012-09-14 14:37:09,671 DEBUG LoggerTestA:15 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,673 INFO LoggerTestA:16 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,673 WARN LoggerTestA:17 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,673 ERROR LoggerTestA:18 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,674 FATAL LoggerTestA:19 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,674 DEBUG LoggerTestB:15 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,675 INFO LoggerTestB:16 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,675 WARN LoggerTestB:17 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,675 ERROR LoggerTestB:18 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,676 FATAL LoggerTestB:19 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,677 DEBUG LoggerTestC:15 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,677 INFO LoggerTestC:16 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,677 WARN LoggerTestC:17 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,677 ERROR LoggerTestC:18 - Logging da configurazione di tipo property file
2012-09-14 14:37:09,678 FATAL LoggerTestC:19 - Logging da configurazione di tipo property file
Custom log (LoggerTestB)
2012-09-14 14:34:47,916 WARN LoggerTestB:17 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,916 ERROR LoggerTestB:18 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,916 FATAL LoggerTestB:19 - Logging da configurazione di tipo property file
Rolling log
2012-09-14 14:34:47,912 DEBUG LoggerTestA:15 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,914 INFO LoggerTestA:16 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,914 WARN LoggerTestA:17 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,914 ERROR LoggerTestA:18 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,915 FATAL LoggerTestA:19 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,927 DEBUG LoggerTestC:15 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,927 INFO LoggerTestC:16 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,928 WARN LoggerTestC:17 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,928 ERROR LoggerTestC:18 - Logging da configurazione di tipo property file
2012-09-14 14:34:47,928 FATAL LoggerTestC:19 - Logging da configurazione di tipo property file
Il Configurator può anche essere utilizzato a partire da un file xml che ci permette di definire alcune altre utili proprietà di log4j presenti solo in questa modalità, mi riferisco ai filtri. L’utilizzo della configurazione mediante file xml presuppone la presenza, sulla nostra applicazione, del file DTD di log4j.
Il questo caso non usiamo il PropertyConfigurator ma il DOMConfigurator:
DOMConfigurator.configure("conf/log4j.xml");
Vediamo lo stesso esempio riadattato.
Supposto di avere sempre le nostre 3 classi LoggerTestA, B e C, ipotizziamo di voler gestire per nostra comodità i seguenti file di log:
- un file di output con i messaggi standard informativi,
- un file di errore per tracciare appunto errori e warning,
- il file di debug sempre di tipo rolling per quanto spiegato in precedenza
- un file dedicato per la classe LoggerTestA
Scarica qui il file log4j.xml e la DTD di log4j.
Infine uno stralcio dei nostri log:
Output log
2012-09-14 14:37:09 INFO LoggerTestA [16] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 INFO LoggerTestA [16] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 WARN LoggerTestA [17] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 WARN LoggerTestA [17] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 INFO LoggerTestB [16] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 INFO LoggerTestB [16] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 WARN LoggerTestB [17] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 WARN LoggerTestB [17] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 INFO LoggerTestC [16] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 INFO LoggerTestC [16] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 WARN LoggerTestC [17] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 WARN LoggerTestC [17] - Logging da configurazione di tipo xml file
Error log
2012-09-14 14:37:09 ERROR LoggerTestA [18] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 FATAL LoggerTestA [19] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 ERROR LoggerTestB [18] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 FATAL LoggerTestB [19] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 ERROR LoggerTestC [18] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 FATAL LoggerTestC [19] - Logging da configurazione di tipo xml file
Debug log
2012-09-14 14:37:09 DEBUG LoggerTestA [15] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 INFO LoggerTestA [16] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 WARN LoggerTestA [17] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 ERROR LoggerTestA [18] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 FATAL LoggerTestA [19] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 DEBUG LoggerTestB [15] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 INFO LoggerTestB [16] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 WARN LoggerTestB [17] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 ERROR LoggerTestB [18] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 FATAL LoggerTestB [19] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 DEBUG LoggerTestC [15] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 INFO LoggerTestC [16] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 WARN LoggerTestC [17] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 ERROR LoggerTestC [18] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 FATAL LoggerTestC [19] - Logging da configurazione di tipo xml file
Custom log (LoggerTestA)
2012-09-14 14:37:09 INFO LoggerTestA [16] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 WARN LoggerTestA [17] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 ERROR LoggerTestA [18] - Logging da configurazione di tipo xml file
2012-09-14 14:37:09 FATAL LoggerTestA [19] - Logging da configurazione di tipo xml file
Chiaro il senso dei filtri?
In pratica possiamo definire il livello massimo e minimo di scrittura, a livello di singolo appender, riuscendo così a dirigere nel modo migliore l’output dell’applicazione secondo le nostre esigenze.
Riferimenti:
http://logging.apache.org/log4j/1.2/
http://it.wikipedia.org/wiki/Log4j
Nessun commento:
Posta un commento