In log4j, la verifica di isDebugEnabled prima della registrazione migliora le prestazioni?

Sto usando Log4J nella mia applicazione per la registrazione. In precedenza stavo usando la chiamata di debug come:

Opzione 1:

logger.debug("some debug text"); 

ma alcuni link suggeriscono che è meglio controllare isDebugEnabled() prima, come:

Opzione 2:

 boolean debugEnabled = logger.isDebugEnabled(); if (debugEnabled) { logger.debug("some debug text"); } 

Quindi la mia domanda è ” L’opzione 2 migliora le prestazioni in qualsiasi modo? “.

Perché in ogni caso il framework Log4J ha lo stesso controllo per debugEnabled. Per l’opzione 2 potrebbe essere utile se stiamo usando più istruzioni di debug in un singolo metodo o class, in cui il framework non ha bisogno di chiamare il metodo isDebugEnabled() più volte (su ogni chiamata); in questo caso chiama il metodo isDebugEnabled() solo una volta e, se Log4J è configurato per il livello di debug, in realtà chiama due volte il metodo isDebugEnabled() :

  1. In caso di assegnazione di valore alla variabile debugEnabled, e
  2. In realtà chiamato dal metodo logger.debug ().

Non penso che se scriviamo più logger.debug() nel metodo o nella class e chiamiamo il metodo debug() base all’opzione 1, allora è overhead per il framework Log4J in confronto con l’opzione 2. Poiché isDebugEnabled() è molto piccolo metodo (in termini di codice), potrebbe essere un buon candidato per l’inlining.

In questo caso particolare, l’opzione 1 è migliore.

L’istruzione guardia (che controlla isDebugEnabled() ) è lì per prevenire il calcolo potenzialmente costoso del messaggio di log quando coinvolge il richiamo dei metodi toString() di vari oggetti e concatenando i risultati.

Nell’esempio riportato, il messaggio di log è una stringa costante, quindi lasciare che il logger lo scarti è altrettanto efficace che controllare se il logger è abilitato e riduce la complessità del codice perché ci sono meno diramazioni.

Meglio ancora usare un framework di registrazione più aggiornato in cui le istruzioni del registro prendono una specifica di formato e un elenco di argomenti che devono essere sostituiti dal registratore, ma “pigramente”, solo se il logger è abilitato. Questo è l’approccio adottato da slf4j .

Vedere la mia risposta a una domanda correlata per maggiori informazioni e un esempio di come fare qualcosa con log4j.

Poiché nell’opzione 1 la stringa di messaggi è una costante, non vi è assolutamente alcun guadagno nel racchiudere l’istruzione di registrazione con una condizione, al contrario, se l’istruzione di registro è abilitata per il debug, verrà valutata due volte, una volta nel metodo isDebugEnabled() e una volta nel metodo debug() . Il costo di invocazione di isDebugEnabled() è dell’ordine di isDebugEnabled() nanosecondi, il che dovrebbe essere trascurabile per la maggior parte degli scopi pratici. Pertanto, l’opzione 2 non è auspicabile perché inquina il tuo codice e non fornisce altri guadagni.

L’uso di isDebugEnabled() è riservato per quando si isDebugEnabled() messaggi di registro concatenando le stringhe:

 Var myVar = new MyVar(); log.debug("My var is " + myVar + ", value:" + myVar.someCall()); 

Tuttavia, nel tuo esempio non c’è guadagno di velocità dato che stai loggando una stringa e non eseguendo operazioni come la concatenazione. Quindi stai solo aggiungendo il tuo codice e rendilo più difficile da leggere.

Io personalmente uso le chiamate in formato Java 1.5 nella class String in questo modo:

 Var myVar = new MyVar(); log.debug(String.format("My var is '%s', value: '%s'", myVar, myVar.someCall())); 

Dubito che ci sia molta ottimizzazione ma è più facile da leggere.

Si noti però che la maggior parte delle API di registrazione offrono una formattazione simile a questa: la slf4j ad esempio fornisce quanto segue:

 logger.debug("My var is {}", myVar); 

che è ancora più facile da leggere.

Versione breve: si potrebbe anche fare il controllo booleano isDebugEnabled ().

Motivi:
1- Se la logica è complicata / stringa concat. viene aggiunto alla tua dichiarazione di debug che avrai già il controllo in atto.
2- Non è necessario includere selettivamente l’istruzione su istruzioni di debug “complesse”. Tutte le dichiarazioni sono incluse in questo modo.
3- La chiamata a log.debug esegue quanto segue prima di accedere:

if(repository.isDisabled(Level.DEBUG_INT))
return;

Questo è fondamentalmente lo stesso del registro delle chiamate. o gatto isDebugEnabled ().

PERÒ! Questo è ciò che pensano gli sviluppatori di log4j (come è nel loro javadoc e dovresti probabilmente passarci sopra).

Questo è il metodo

 public boolean isDebugEnabled() { if(repository.isDisabled( Level.DEBUG_INT)) return false; return Level.DEBUG.isGreaterOrEqual(this.getEffectiveLevel()); } 

Questo è il javadoc per questo

 /** * Check whether this category is enabled for the DEBUG * Level. * * 

This function is intended to lessen the computational cost of * disabled log debug statements. * *

For some cat Category object, when you write, *

 * cat.debug("This is entry number: " + i ); * 

* *

You incur the cost constructing the message, concatenatiion in * this case, regardless of whether the message is logged or not. * *

If you are worried about speed, then you should write *

 * if(cat.isDebugEnabled()) { * cat.debug("This is entry number: " + i ); * } * 

* *

This way you will not incur the cost of parameter * construction if debugging is disabled for cat. On * the other hand, if the cat is debug enabled, you * will incur the cost of evaluating whether the category is debug * enabled twice. Once in isDebugEnabled and once in * the debug. This is an insignificant overhead * since evaluating a category takes about 1%% of the time it * takes to actually log. * * @return boolean - true if this category is debug * enabled, false otherwise. * */

L’opzione 2 è migliore.

Di per sé non migliora le prestazioni. Ma assicura che le prestazioni non si degradino. Ecco come.

Normalmente ci aspettiamo logger.debug (someString);

Ma di solito, man mano che l’applicazione cresce, cambiano molte mani, gli sviluppatori alle prime armi, si potrebbe vedere

logger.debug (str1 + str2 + str3 + str4);

e simili.

Anche se il livello di log è impostato su ERROR o FATAL, la concatenazione di stringhe si verifica! Se l’applicazione contiene molti messaggi di livello DEBUG con concatenazioni di stringhe, allora sicuramente richiede un colpo di prestazioni, specialmente con jdk 1.4 o inferiore. (Non sono sicuro che le versioni successive di jdk internall facciano qualsiasi stringbuffer.append ()).

Ecco perché l’opzione 2 è sicura. Anche le concatenazioni di stringhe non accadono.

Come altri hanno menzionato usando la dichiarazione di guardia è veramente utile se la creazione della stringa è una chiamata che richiede tempo. Esempi specifici di questo sono quando la creazione della stringa attiverà un caricamento lento.

Vale la pena notare che questo problema può essere completato evitando l’uso di Simple Logging Facade per Java o (SLF4J) – http://www.slf4j.org/manual.html . Ciò consente chiamate di metodo come:

 logger.debug("Temperature set to {}. Old temperature was {}.", t, oldT); 

Questo convertirà i parametri passati in stringhe solo se il debug è abilitato. SLF4J come suggerisce il nome è solo una facciata e le chiamate di registrazione possono essere passate a log4j.

Si potrebbe anche facilmente “arrotolare la propria” versione di questo.

Spero che questo ti aiuti.

In Java 8, non è necessario utilizzare isDebugEnabled() per migliorare le prestazioni.

https://logging.apache.org/log4j/2.0/manual/api.html#Java_8_lambda_support_for_lazy_logging

 import java.util.logging.Logger; ... Logger.getLogger("hello").info(() -> "Hello " + name); 

Come @erickson dipende. Se ricordo, isDebugEnabled è già isDebugEnabled nel metodo debug() di Log4j.
Finché non esegui calcoli costosi nelle tue istruzioni di debug, come il loop sugli oggetti, i calcoli e le stringhe concatenate, a mio avviso stai bene.

 StringBuilder buffer = new StringBuilder(); for(Object o : myHugeCollection){ buffer.append(o.getName()).append(":"); buffer.append(o.getResultFromExpensiveComputation()).append(","); } log.debug(buffer.toString()); 

sarebbe meglio come

 if (log.isDebugEnabled(){ StringBuilder buffer = new StringBuilder(); for(Object o : myHugeCollection){ buffer.append(o.getName()).append(":"); buffer.append(o.getResultFromExpensiveComputation()).append(","); } log.debug(buffer.toString()); } 

Migliora la velocità perché è comune concatenare stringhe nel testo di debug che è costoso, ad esempio:

 boolean debugEnabled = logger.isDebugEnabled(); if (debugEnabled) { logger.debug("some debug text" + someState); } 

Per una singola riga , utilizzo un ternario all’interno del messaggio di registrazione, in questo modo non eseguo la concatenazione:

ej:

 logger.debug(str1 + str2 + str3 + str4); 

Lo voglio:

 logger.debug(logger.isDebugEnable()?str1 + str2 + str3 + str4:null); 

Ma per più righe di codice

ej.

 for(Message mess:list) { logger.debug("mess:" + mess.getText()); } 

Lo voglio:

 if(logger.isDebugEnable()) { for(Message mess:list) { logger.debug("mess:" + mess.getText()); } } 

Se si utilizza l’opzione 2, si sta eseguendo un controllo booleano che è veloce. Nell’opzione 1 si sta facendo una chiamata al metodo (spingendo cose in pila) e poi facendo un controllo booleano che è ancora veloce. Il problema che vedo è la coerenza. Se alcune delle tue istruzioni di debug e informazioni sono incapsulate e altre no, non è uno stile di codice coerente. Inoltre qualcuno in seguito potrebbe modificare l’istruzione di debug per includere stringhe concatenate, che è ancora piuttosto veloce. Ho scoperto che quando abbiamo eseguito il debug e l’istruzione info in una grande applicazione e l’abbiamo profilata, abbiamo risparmiato un paio di punti percentuali nelle prestazioni. Non molto, ma abbastanza per farlo valere il lavoro. Ora ho un paio di impostazioni di macro in IntelliJ per generare automaticamente dichiarazioni di debug e informazioni avvolte per me.

Dal momento che molte persone stanno probabilmente visualizzando questa risposta durante la ricerca di log4j2 e quasi tutte le risposte correnti non considerano log4j2 o le modifiche recenti in esso, si spera che risponda alla domanda.

log4j2 supporta i fornitori (attualmente la loro implementazione, ma secondo la documentazione è previsto l’utilizzo dell’interfaccia fornitore di Java nella versione 3.0). Puoi leggere un po ‘di più su questo nel manuale . Ciò consente di inserire una costosa creazione di messaggi di registro in un fornitore che crea il messaggio solo se deve essere registrato:

 LogManager.getLogger().debug(() -> createExpensiveLogMessage()); 

A partire da 2.x, Apache Log4j ha questo controllo integrato, quindi avere isDebugEnabled() non è più necessario. Basta fare un debug() e i messaggi saranno soppressi se non abilitati.

Log4j2 consente di formattare i parametri in un modello di messaggio, simile a String.format() , eliminando così la necessità di eseguire isDebugEnabled() .

 Logger log = LogManager.getFormatterLogger(getClass()); log.debug("Some message [myField=%s]", myField); 

Esempio semplice log4j2.properties:

 filter.threshold.type = ThresholdFilter filter.threshold.level = debug appender.console.type = Console appender.console.name = STDOUT appender.console.layout.type = PatternLayout appender.console.layout.pattern = %d %-5p: %c - %m%n appender.console.filter.threshold.type = ThresholdFilter appender.console.filter.threshold.level = debug rootLogger.level = info rootLogger.appenderRef.stdout.ref = STDOUT 

Consiglierei l’utilizzo dell’opzione 2 come di fatto per la maggior parte in quanto non è super costoso.

Caso 1: log.debug (“una stringa”)

Case2: log.debug (“una stringa” + “due stringhe” + object.toString + object2.toString)

Nel momento in cui viene chiamato uno di questi, la stringa di parametri all’interno di log.debug (sia CASE 1 o Case2) deve essere valutata. Questo è ciò che intendiamo per “costoso”. Se si ha una condizione prima di essa, ‘isDebugEnabled ()’, non è necessario valutare questi valori, ovvero il luogo in cui viene salvata la performance.