cosa fa in realtà log4j quando accendiamo o spegniamo alcuni luoghi di log?

Question

Sappiamo che possiamo configare log4j per disattivare il log in luoghi specifici (classe o pacchetto in Java) tramite le sue proprietà/file di configurazione. Le mie domande sono seguite:

1. cosa sta facendo log4j per quelle bandiere?
2. è l'istruzione di registro in log4j ancora chiamata ma non viene semplicemente scritta su file o console a causa di tale flag? quindi hanno ancora un impatto sulle prestazioni?
3. è come #ifdef in C++ che ha effetto in fase di compilazione, quindi può limitare l'impatto sulle prestazioni?

grazie,

Answer 1

Sì, saranno ancora eseguite le istruzioni di registro. Questo è il motivo per cui si tratta di un buon modello per controllare il livello di log prima: qualcosa di simile

if (log.isInfoEnabled()) { 
    log.info("My big long info string: " + someMessage); 
} 

Questo per evitare di riallocare lo spazio per le informazioni String quando il livello di log non supporta INFO dichiarazioni.

Non è niente come #ifdef - #ifdef è una direttiva del compilatore, mentre le configurazioni di Log4J vengono elaborate in fase di esecuzione.

Modifica: Odio ottenere downmodded a causa di ignoranza, quindi ecco un articolo di backup della mia risposta.

Da http://surguy.net/articles/removing-log-messages.xml:

In Log4J, se si accede un messaggio a livello di debug, e l'Appender corrente è impostato per accedere solo i messaggi di INFO livello e al di sopra, quindi il messaggio non essere visualizzato. La penalità delle prestazioni per chiamare il metodo log è minima: pochi nanosecondi. Tuttavia, potrebbe essere necessario più tempo per valutare gli argomenti nel metodo registro . Ad esempio:

logger.debug ("L'oggetto grande è " + largeObject.toString());

valutazione largeObject.toString() può essere lento, e viene valutata prima la chiamata allo strumento, in modo che il registratore non può impedire che venga valutata anche se non viene utilizzato.

Edit 2: dal manuale log4j stesso (http://logging.apache.org/log4j/1.2/manual.html):

l'utente deve essere a conoscenza dei seguenti problemi di prestazioni.

1. Prestazioni di registrazione quando la registrazione è disattivata. Quando la registrazione è completamente disattivata o solo per un insieme di livelli, il costo di una richiesta di registro consiste in una chiamata al metodo più un confronto tra numeri interi. Su una macchina Pentium II a 233 MHz questo costo è in genere nell'intervallo da 5 a 50 nanosecondi.

   Tuttavia, l'invocazione del metodo comporta il costo "nascosto" della costruzione dei parametri.

   Ad esempio, per alcuni logger gatto, la scrittura,

   logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i])); 
   

   comporta il costo di costruzione del parametro messaggio, vale a dire la conversione sia intero i e l'ingresso [i] in una stringa, e concatenazione di stringhe intermedi, a prescindere se il messaggio verrà registrato o meno. Questo costo di costruzione dei parametri può essere piuttosto elevato e dipende dalla dimensione dei parametri coinvolti.

   Per evitare il parametro costo di costruzione di scrittura:

   if(logger.isDebugEnabled() { 
       logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i])); 
   } 
   

   questo non sostenere il costo di costruzione parametro se il debug è disattivato. D'altra parte, se il logger è abilitato per il debug, avrà il doppio del costo di valutare se il logger è abilitato o meno: una volta in debugEnabled e una volta nel debug. Si tratta di un overhead insignificante poiché la valutazione di un logger richiede circa l'1% del tempo necessario per la registrazione effettiva.

Answer 2

1. log4j elaborerà la dichiarazione di registro e verificare se il particolare logger è abilitato al particolare livello di registrazione. In caso contrario, la dichiarazione non verrà registrata.

2. Questi controlli sono significativamente meno costosi della scrittura effettiva su disco (o console), ma hanno comunque un impatto.

3. no, Java non ha tale concetto come #ifdef (out of the box in ogni caso, ci sono precompilatori Java là fuori)

Answer 3

ho eseguito una semplice benchmark per testare.

for (int j = 0; j < 5; j++) { 
     long t1 = System.nanoTime()/1000000; 
     int iterations = 1000000; 
     for (int i = 0; i < iterations; i++) { 
      int test = i % 10; 
      log.debug("Test " + i + " has value " + test); 
     } 
     long t2 = System.nanoTime()/1000000; 
     log.info("elapsed time: " + (t2 - t1)); 

     long t3 = System.nanoTime()/1000000; 
     for (int i = 0; i < iterations; i++) { 
      int test = i % 10; 
      if (log.isDebugEnabled()) { 
       log.debug("Test " + i + " has value " + test); 
      } 
     } 
     long t4 = System.nanoTime()/1000000; 
     log.info("elapsed time 2: " + (t4 - t3)); 
    } 

elapsed time: 539 
elapsed time 2: 17 
elapsed time: 450 
elapsed time 2: 18 
elapsed time: 454 
elapsed time 2: 19 
elapsed time: 454 
elapsed time 2: 17 
elapsed time: 450 
elapsed time 2: 19 

Con 1.6.0_18, che mi ha sorpreso come avrei pensato che l'inline avrebbe impedito questo. Forse sarà Java 7 con l'analisi di escape.

Tuttavia, non vorrei ancora eseguire il wrap delle istruzioni di debug in una clausola if a meno che i miglioramenti del tempo dell'ordine di mezzo microsecondo non siano importanti!