2009-06-08 7 views
145

Estoy usando Log4J en mi aplicación para el registro. Anteriormente yo estaba usando la llamada de depuración como:En log4j, ¿la comprobación es DebugEnabled antes de iniciar sesión mejora el rendimiento?

Opción 1:

logger.debug("some debug text"); 

pero algunos enlaces sugieren que es mejor para comprobar isDebugEnabled() principio, como:

Opción 2:

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

Así que mi pregunta es "¿La opción 2 mejora el rendimiento de alguna manera?".

Debido a que en cualquier caso marco Log4J tienen el mismo cheque por debugEnabled. Para la opción 2 podría ser beneficioso si estamos utilizando instrucciones de depuración múltiple en un solo método o clase, en el que el marco no necesita llamar isDebugEnabled() método múltiple veces (en cada llamada); en este caso se llama isDebugEnabled() método sólo una vez, y si Log4J está configurado para el nivel de depuración luego en realidad se llama isDebugEnabled() método dos veces:

  1. en caso de asignar un valor a la variable debugEnabled y
  2. En realidad llamado por el método logger.debug()

No creo que si escribimos múltiples logger.debug() comunicado en el método o la clase y llamar debug() método de acuerdo con la opción 1, entonces es por encima de marco Log4J en comparación con la opción 2. Desde isDebugEnabled() es un método muy pequeña (en términos de código), podría ser un buen candidato para la alineación.

Respuesta

173

En este caso particular, la Opción 1 es mejor.

La instrucción de guardia (marcando isDebugEnabled()) está ahí para evitar el cálculo potencialmente costoso del mensaje de registro cuando implica la invocación de los métodos toString() de varios objetos y concatenar los resultados.

En el ejemplo dado, el mensaje de registro es una cadena constante, por lo que dejar que el registrador lo descarte es tan eficiente como verificar si el registrador está habilitado, y reduce la complejidad del código porque hay menos ramas.

Mejor aún es utilizar un marco de registro más actualizado donde las instrucciones de registro toman una especificación de formato y una lista de argumentos para ser sustituidos por el registrador — pero "perezosamente", solo si el registrador está habilitado. Este es el enfoque adoptado por slf4j.

Consulte my answer to a related question para obtener más información y un ejemplo de cómo hacer algo como esto con log4j.

+3

log5j extiende log4j casi de la misma manera que slf4j –

+0

Este es también el enfoque de java.util.Logging. – Paul

+0

@erickson ¿Cuál es el beneficio del formateador? – Geek

2

mejora la velocidad, ya que es común para concatenar cadenas en el texto de depuración que es caro por ejemplo:

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

Si estamos utilizando JDK 1.5 en adelante y luego me lo creo concatenar cadenas no hará ninguna diferencia. –

+0

¿Cómo es que vino? ¿Qué haría JDK5 de manera diferente? – javashlook

+0

En jdk 1.5 si concatenamos cadenas en una instrucción única, internamente utiliza el método StringBuffer.append() solamente. Por lo tanto, no afecta el rendimiento. –

6

Opción 2 es mejor.

Per se no mejora el rendimiento. Pero asegura que el rendimiento no se degrada. Así es cómo.

Normalmente esperamos logger.debug (someString);

Pero por lo general, ya que la aplicación crece, cambia muchas manos, ESP desarrolladores novatos, se podía ver

logger.debug (cadena1 + cadena2 + + str3 STR4);

y similares.

Incluso si el nivel de registro está configurado en ERROR o FATAL, la concatenación de cadenas ocurre. Si la aplicación contiene muchos mensajes de nivel de DEPURACIÓN con concatenaciones de cadenas, entonces ciertamente requiere un golpe de rendimiento especialmente con jdk 1.4 o menos. (No estoy seguro si las versiones posteriores de jdk internall hacen cualquier stringbuffer.append()).

Es por eso que la Opción 2 es segura. Incluso las concatenaciones de cadenas no ocurren.

13

Utilizando el isDebugEnabled() se reserva para cuando se está construyendo mensajes de registro por cadenas concatenación:

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

Sin embargo, en su ejemplo que no hay aumento de velocidad que sólo estás registrar una cadena y no realizar operaciones tales como concatenación. Por lo tanto, solo está agregando relleno a su código y haciendo que sea más difícil de leer.

Yo personalmente uso de las llamadas de Java 1.5 del formato de la clase cadena como esta:

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

dudo que haya mucha optimización, pero es más fácil de leer.

hacer la nota sin embargo que la mayoría de las API de registro ofrecen este formato, como fuera de la caja: slf4j por ejemplo, proporciona la siguiente:

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

que es aún más fácil de leer.

+3

Su uso de String.format (...), al hacer que la línea de registro sea más fácil de leer, de hecho puede afectar el rendimiento de una manera incorrecta. La forma de hacerlo de SLF4J envía los parámetros al método logger.debug y allí se realiza la evaluación de isDebugEnabled _antes de que se construya la cadena. De la forma en que lo está haciendo, con String.format (...), la cadena se construirá antes de que se realice la llamada al método a logger.debug, por lo que habrá pagado la penalización de la construcción de cadena incluso si la depuración el nivel no está habilitado Lo siento por la recolección de liendres, simplemente tratando de evitar la confusión para los novatos ;-) – StFS

+0

String.format es 40 veces más lento que concat y slf4j tiene una limitación de 2 params Ver números aquí: https://stackoverflow.com/questions/ 925423/is-it-better-practice-to-use-string-format-over-string-concatenation-in-java # 925444 He visto muchos gráficos de perfiles donde la operación de formato se desperdicia en instrucciones de depuración cuando la producción el sistema se ejecuta en el nivel de registro de INFO o ERROR –

25

Dado que en la opción 1 la cadena del mensaje es una constante, no hay absolutamente ninguna ganancia en envolver la declaración de registro con una condición, por el contrario, si la instrucción de registro está habilitada para la depuración, se evaluará dos veces, una en el isDebugEnabled() método y una vez en debug() método. El costo de invocar isDebugEnabled() es del orden de 5 a 30 nanosegundos, lo que debería ser insignificante para la mayoría de los propósitos prácticos. Por lo tanto, la opción 2 no es deseable porque contamina su código y no proporciona ninguna otra ganancia.

3

Me gusta @erickson it depends. Si no recuerdo mal, isDebugEnabled ya está compilado en el método debug() de Log4j.
Siempre que no esté haciendo cálculos costosos en sus instrucciones de depuración, como bucle en objetos, realice cálculos y concatene cadenas, está bien en mi opinión.

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

sería mejor como

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()); 
} 
0

Si la opción 2 que está haciendo una verificación lógica, que es rápido de utilizar. En la opción uno estás haciendo una llamada a método (empujando cosas en la pila) y luego haciendo una verificación booleana que todavía es rápida. El problema que veo es consistencia.Si algunas de sus declaraciones de depuración e información están incluidas y otras no, no es un estilo de código consistente. Además, alguien más adelante podría cambiar la declaración de depuración para incluir cadenas de concatenación, lo cual es aún bastante rápido. Descubrí que cuando completamos la declaración de depuración y de información en una aplicación grande y la perfilamos, ahorramos un par de puntos porcentuales en el rendimiento. No mucho, pero suficiente para que valga la pena el trabajo. Ahora tengo un par de configuraciones de macros en IntelliJ para generar automáticamente las declaraciones envueltas de depuración e información para mí.

5

Como otros han mencionado usar el enunciado de guardia solo es realmente útil si la creación de la cadena es una llamada que consume mucho tiempo. Ejemplos específicos de esto son cuando la creación de la cadena provocará una carga diferida.

Vale la pena señalar que se puede evitar este problema utilizando Simple Logging Facade para Java o (SLF4J) - http://www.slf4j.org/manual.html. Esto permite que las llamadas a métodos tales como:

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

Esto sólo convertir el pasado en los parámetros de depuración en cadenas si está activado. SLF4J como su nombre lo indica es solo una fachada y las llamadas de registro se pueden pasar a log4j.

También podría muy fácilmente "hacer su propia versión" de esto.

Espero que esto ayude.

6

Versión corta: también podría hacer la comprobación booleana isDebugEnabled().

Razones:
1- If complicated logic/string concat. se agrega a su declaración de depuración ya tendrá el cheque en su lugar.
2- No tiene que incluir selectivamente la declaración en las instrucciones de depuración "complejas". Todas las declaraciones están incluidas de esa manera.
3- Log.DEBUG Calling ejecuta lo siguiente antes de la tala:

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

Esto es básicamente lo mismo que llamar registro. o gato isDebugEnabled().

¡SIN EMBARGO! Esto es lo que piensan los desarrolladores de log4j (como lo es en su javadoc y probablemente debería ir por ella.)

Este es el método

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

Este es el Javadoc para que

/** 
* Check whether this category is enabled for the <code>DEBUG</code> 
* Level. 
* 
* <p> This function is intended to lessen the computational cost of 
* disabled log debug statements. 
* 
* <p> For some <code>cat</code> Category object, when you write, 
* <pre> 
*  cat.debug("This is entry number: " + i); 
* </pre> 
* 
* <p>You incur the cost constructing the message, concatenatiion in 
* this case, regardless of whether the message is logged or not. 
* 
* <p>If you are worried about speed, then you should write 
* <pre> 
* if(cat.isDebugEnabled()) { 
*  cat.debug("This is entry number: " + i); 
* } 
* </pre> 
* 
* <p>This way you will not incur the cost of parameter 
* construction if debugging is disabled for <code>cat</code>. On 
* the other hand, if the <code>cat</code> is debug enabled, you 
* will incur the cost of evaluating whether the category is debug 
* enabled twice. Once in <code>isDebugEnabled</code> and once in 
* the <code>debug</code>. This is an insignificant overhead 
* since evaluating a category takes about 1%% of the time it 
* takes to actually log. 
* 
* @return boolean - <code>true</code> if this category is debug 
* enabled, <code>false</code> otherwise. 
* */ 
+0

Gracias por incluir JavaDoc. Sabía que había visto este consejo en alguna parte antes y estaba tratando de encontrar una referencia definitiva. Esto es, si no definitivo, al menos muy bien informado. –

-1

Recomendaría utilizar la Opción 2 de facto para la mayoría, ya que no es muy caro.

Caso 1: Log.DEBUG ("una cadena")

Caso 2: Log.DEBUG ("una cadena" + "dos cuerdas" + + Object.toString object2.toString)

En el momento en que se llama a cualquiera de estos, se debe evaluar la cadena de parámetros dentro de log.debug (ya sea CASO 1 o Caso2). Eso es lo que todos quieren decir con "caro". Si tiene una condición antes, 'isDebugEnabled()', no es necesario evaluarlos, que es donde se guarda el rendimiento.

2

Para una sola línea, uso un ternario interior de registro de mensajes, De esta manera no hago la concatenación:

ej:

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

hago:

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

Pero para líneas múltiples del código

ej.

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

hago:

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