language agnostic - Registro condicional con mínima complejidad ciclomática

language-agnostic logging

Question

Después de leer " ¿Cuál es su / un buen límite para la complejidad ciclomática? ", Me doy cuenta de que muchos de mis colegas estaban bastante molestos con esta nueva política de QA de nuestro proyecto: no más de 10 complejidades ciclomáticas por función.

Significado: no más de 10 ''if'', ''else'', ''try'', ''catch'' y otra instrucción de código de flujo de trabajo de bifurcación. Derecha. Como expliqué en '' ¿Probas el método privado? '', tal política tiene muchos buenos efectos secundarios.

Pero: al comienzo de nuestro proyecto (200 personas - 7 años), estábamos felizmente iniciando la sesión (y no, no podemos delegar fácilmente eso en algún tipo de enfoque de " programación orientada a aspectos " para los registros).

myLogger.info("A String");
myLogger.fine("A more complicated String");
...

Y cuando las primeras versiones de nuestro sistema se activaron, experimentamos un gran problema de memoria no debido al registro (que en un momento se apagó), sino debido a los parámetros de registro (las cadenas), que siempre se calculan, y luego pasaron a las funciones ''info ()'' o ''fine ()'', solo para descubrir que el nivel de registro estaba ''DESACTIVADO'', ¡y que no se estaba registrando!

Entonces QA regresó e instó a nuestros programadores a hacer un registro condicional. Siempre.

if(myLogger.isLoggable(Level.INFO) { myLogger.info("A String");
if(myLogger.isLoggable(Level.FINE) { myLogger.fine("A more complicated String");
...

Pero ahora, con ese nivel de complejidad ciclomática "no se puede mover" por límite de función, argumentan que los diversos registros que ponen en su función se sienten como una carga, porque cada "if (isLoggable ())" es ¡contado como +1 complejidad ciclomática!

Entonces, si una función tiene 8 ''si'', ''else'', etc., en un algoritmo estrechamente acoplado que no se puede compartir fácilmente, y 3 acciones de registro críticas ... quebrantarán el límite aunque los registros condicionales no sean realmente parte de dicha complejidad de esa función ...

¿Cómo abordarías esta situación?
He visto un par de evoluciones de codificación interesantes (debido a ese "conflicto") en mi proyecto, pero solo quiero que primero piensen primero.

Gracias por todas las respuestas.
Debo insistir en que el problema no está relacionado con el "formateo", sino que está relacionado con la "evaluación de los argumentos" (una evaluación que puede ser muy costosa, justo antes de llamar a un método que no hará nada)
Así que cuando escribí arriba "A String", en realidad me refería a aFunction (), con aFunction () devolviendo un String, y siendo una llamada a un complicado método de recopilación y cálculo de todo tipo de datos de registro para ser exhibidos por el registrador ... o no (de ahí el problema y la obligación de usar la tala condicional, de ahí el problema real del aumento artificial de la "complejidad ciclomática" ...)

Ahora obtengo el punto de ''función variadic '' avanzado por algunos de ustedes (gracias John).
Nota: una prueba rápida en java6 muestra que mi función varargs evalúa sus argumentos antes de ser llamada, por lo que no se puede aplicar a llamadas de función, sino a ''Log retriever object'' (o ''function wrapper''), en el cual toString ( ) solo se llamará si es necesario. Lo tengo.

Ahora he publicado mi experiencia en este tema.
Lo dejaré allí hasta el próximo martes para votar, luego seleccionaré una de tus respuestas.
De nuevo, gracias por todas las sugerencias :)

Answer 1

Con los marcos de registro actuales, la pregunta es discutible

Los marcos de registro actuales como slf4j o log4j 2 no requieren resguardos en la mayoría de los casos. Utilizan una declaración de registro parametrizada para que un evento pueda registrarse incondicionalmente, pero el formato de mensaje solo se produce si el evento está habilitado. La construcción del mensaje se realiza según lo necesite el registrador, en lugar de hacerlo preventivamente por la aplicación.

Si tiene que usar una biblioteca de registro antigua, puede seguir leyendo para obtener más información y una forma de actualizar la biblioteca anterior con mensajes parametrizados.

¿Las declaraciones de los guardias realmente agregan complejidad?

Considere la posibilidad de excluir las declaraciones de guardias de registro del cálculo de complejidad ciclomática.

Podría argumentarse que, debido a su forma predecible, las comprobaciones de registro condicional realmente no contribuyen a la complejidad del código.

Las mediciones inflexibles pueden hacer que un programador por lo demás bueno se vuelva malo. ¡Ten cuidado!

Suponiendo que sus herramientas para calcular la complejidad no se pueden adaptar a ese grado, el siguiente enfoque puede ofrecer una solución alternativa.

La necesidad de registro condicional

Supongo que sus declaraciones de guardia fueron introducidas porque tenía un código como este:

private static final Logger log = Logger.getLogger(MyClass.class);

Connection connect(Widget w, Dongle d, Dongle alt) 
  throws ConnectionException
{
  log.debug("Attempting connection of dongle " + d + " to widget " + w);
  Connection c;
  try {
    c = w.connect(d);
  } catch(ConnectionException ex) {
    log.warn("Connection failed; attempting alternate dongle " + d, ex);
    c = w.connect(alt);
  }
  log.debug("Connection succeeded: " + c);
  return c;
}

En Java, cada una de las instrucciones de registro crea un nuevo StringBuilder e invoca el método toString() en cada objeto concatenado a la cadena. Estos métodos toString() , a su vez, pueden crear sus propias instancias de StringBuilder e invocar los métodos toString() de sus miembros, y así sucesivamente, en un gráfico de objetos potencialmente grande. (Antes de Java 5, era aún más costoso, ya que se usaba StringBuffer , y todas sus operaciones están sincronizadas).

Esto puede ser relativamente costoso, especialmente si la declaración de registro está en alguna ruta de código muy ejecutada. Y, escrito como se indica anteriormente, ese formato de mensaje costoso se produce incluso si el registrador está obligado a descartar el resultado porque el nivel de registro es demasiado alto.

Esto lleva a la introducción de declaraciones de guardia del formulario:

  if (log.isDebugEnabled())
    log.debug("Attempting connection of dongle " + d + " to widget " + w);

Con este protector, la evaluación de los argumentos d y w y la concatenación de cadenas se realiza solo cuando es necesario.

Una solución para el registro simple y eficiente

Sin embargo, si el registrador (o un contenedor que escribe alrededor del paquete de registro elegido) toma un formateador y argumentos para el formateador, la construcción del mensaje se puede retrasar hasta que sea cierto que se usará, mientras se eliminan las declaraciones de guardia y sus complejidad ciclomática.

public final class FormatLogger
{

  private final Logger log;

  public FormatLogger(Logger log)
  {
    this.log = log;
  }

  public void debug(String formatter, Object... args)
  {
    log(Level.DEBUG, formatter, args);
  }

  … &c. for info, warn; also add overloads to log an exception …

  public void log(Level level, String formatter, Object... args)
  {
    if (log.isEnabled(level)) {
      /* 
       * Only now is the message constructed, and each "arg"
       * evaluated by having its toString() method invoked.
       */
      log.log(level, String.format(formatter, args));
    }
  }

}

class MyClass 
{

  private static final FormatLogger log = 
     new FormatLogger(Logger.getLogger(MyClass.class));

  Connection connect(Widget w, Dongle d, Dongle alt) 
    throws ConnectionException
  {
    log.debug("Attempting connection of dongle %s to widget %s.", d, w);
    Connection c;
    try {
      c = w.connect(d);
    } catch(ConnectionException ex) {
      log.warn("Connection failed; attempting alternate dongle %s.", d);
      c = w.connect(alt);
    }
    log.debug("Connection succeeded: %s", c);
    return c;
  }

}

Ahora, ninguna de las llamadas en cascada toString() con sus asignaciones de búfer se realizará a menos que sean necesarias. Esto efectivamente elimina el golpe de rendimiento que llevó a las declaraciones de guardia. Una pequeña penalización, en Java, sería el auto-boxeo de cualquier argumento de tipo primitivo que pase al registrador.

El código que hace el registro es posiblemente incluso más limpio que nunca, ya que la concatenación de cadenas desordenadas se ha ido. Puede ser incluso más limpio si las cadenas de formato se externalizan (utilizando un ResourceBundle ), lo que también podría ayudar en el mantenimiento o la localización del software.

Mejoras adicionales

También tenga en cuenta que, en Java, podría utilizarse un objeto MessageFormat en lugar de una String "formato", que le brinda capacidades adicionales, como un formato de elección para manejar los números cardinales de forma más clara. Otra alternativa sería implementar su propia capacidad de formato que invoque alguna interfaz que defina para "evaluación", en lugar del método básico toString() .

Answer 2

¡Gracias por todas tus respuestas! Ustedes molan :)

Ahora mi comentario no es tan directo como el tuyo:

Sí, para un proyecto (como en "un programa implementado y funcionando por sí solo en una única plataforma de producción"), supongo que puede consultarme todos los aspectos técnicos:

• objetos dedicados ''Log Retriever'', que se pueden pasar a un contenedor Logger que solo llama a String () es necesario
• ¡se usa junto con una variadic registro (o una matriz simple Object []!)

y ahí lo tienes, como lo explican @John Millikin y @erickson.

Sin embargo, este problema nos obligó a pensar un poco sobre ''¿Por qué exactamente estábamos iniciando sesión en primer lugar?''
Nuestro proyecto es en realidad 30 proyectos diferentes (de 5 a 10 personas cada uno) implementados en diversas plataformas de producción, con necesidades de comunicación asíncrona y arquitectura de bus central.
El registro simple descrito en la pregunta estaba bien para cada proyecto al principio (hace 5 años), pero desde entonces, tenemos que intensificar. Ingrese el KPI .

En lugar de pedirle a un registrador que registre algo, le pedimos a un objeto creado automáticamente (llamado KPI) que registre un evento. Es una llamada simple (myKPI.I_am_signaling_myself_to_you ()), y no necesita ser condicional (lo que resuelve el problema del ''aumento artificial de la complejidad ciclomática'').

Ese objeto KPI sabe quién lo llama y, dado que se ejecuta desde el comienzo de la aplicación, puede recuperar muchos datos que estábamos calculando previamente en el momento en que estábamos iniciando sesión.
Además, el objeto KPI puede monitorearse independientemente y computar / publicar a pedido su información en un solo bus de publicación separado.
De esta forma, cada cliente puede solicitar la información que realmente desea (por ejemplo, ''¿ha comenzado mi proceso y, en caso afirmativo, desde cuándo?''), En lugar de buscar el archivo de registro correcto y buscar una cadena críptica ...

De hecho, la pregunta ''¿Por qué exactamente estábamos iniciando sesión en primer lugar?'' nos hizo darnos cuenta de que no estábamos registrando solo para el programador y su unidad o pruebas de integración, sino para una comunidad mucho más amplia que incluye algunos de los clientes finales. Nuestro mecanismo de ''informes'' tenía que ser centralizado, asincrónico, 24/7.

Lo específico de ese mecanismo de KPI está fuera del alcance de esta pregunta. Baste decir que su calibración correcta es, con mucho, sin dudas, el problema no funcional más complicado que enfrentamos. ¡Todavía pone al sistema de rodillas de vez en cuando! Correctamente calibrado, sin embargo, es un salvavidas.

De nuevo, gracias por todas las sugerencias. Los consideraremos para algunas partes de nuestro sistema cuando el registro simple todavía está en su lugar.
Pero el otro punto de esta pregunta fue ilustrar un problema específico en un contexto mucho más grande y complicado.
Espero que les haya gustado. Podría hacer una pregunta sobre KPI (que, según creo o no, no está en ninguna cuestión en SOF hasta ahora!) Más adelante la próxima semana.

Dejaré esta respuesta para votar hasta el próximo martes, luego seleccionaré una respuesta (obviamente no esta;))

Answer 3

Aquí hay una solución elegante que usa expresión ternaria

logger.info (logger.isInfoEnabled ()? "La declaración del registro va aquí ...": null);

Answer 4

Considere una función de utilidad de registro ...

void debugUtil(String s, Object… args) {
   if (LOG.isDebugEnabled())
       LOG.debug(s, args);
   }
);

Luego realice la llamada con un "cierre" alrededor de la costosa evaluación que desea evitar.

debugUtil(“We got a %s”, new Object() {
       @Override String toString() { 
       // only evaluated if the debug statement is executed
           return expensiveCallToGetSomeValue().toString;
       }
    }
);

Answer 5

El registro condicional es malo. Agrega desorden innecesario a tu código.

Siempre debe enviar los objetos que tiene al registrador:

Logger logger = ...
logger.log(Level.DEBUG,"The foo is {0} and the bar is {1}",new Object[]{foo, bar});

y luego tiene un java.util.logging.Formatter que usa MessageFormat para aplanar foo y bar en la cadena a la salida. Solo se invocará si el registrador y el manejador iniciarán sesión en ese nivel.

Para mayor placer, podría tener algún tipo de lenguaje de expresión para poder tener un control preciso sobre cómo formatear los objetos registrados (toString puede no ser siempre útil).

Answer 6

En C o C ++ usaría el preprocesador en lugar de las declaraciones if para el registro condicional.

Answer 7

En Python pasa los valores formateados como parámetros a la función de registro. El formato de cadena solo se aplica si el registro está habilitado. Todavía hay una sobrecarga de funciones, pero eso es minúsculo en comparación con el formateo.

log.info ("a = %s, b = %s", a, b)

Puede hacer algo como esto para cualquier idioma con argumentos variados (C / C ++, C # / Java, etc.).

Esto no está pensado para cuando los argumentos son difíciles de recuperar, pero cuando formatearlos en cadenas es costoso. Por ejemplo, si su código ya tiene una lista de números, es posible que desee registrar esa lista para la depuración. Ejecutar mylist.toString() tomará un tiempo sin ningún beneficio, ya que el resultado será desechado. Entonces pasa mylist como un parámetro a la función de registro, y deja que maneje el formato de cadenas. De esta forma, el formateo solo se realizará si es necesario.

Dado que la pregunta de OP menciona específicamente Java, aquí se explica cómo se puede usar lo anterior:

Debo insistir en que el problema no está relacionado con el "formateo", sino que está relacionado con la "evaluación de los argumentos" (una evaluación que puede ser muy costosa, justo antes de llamar a un método que no hará nada)

El truco es tener objetos que no realicen cálculos costosos hasta que sea absolutamente necesario. Esto es fácil en lenguajes como Smalltalk o Python que admiten lambdas y cierres, pero todavía es factible en Java con un poco de imaginación.

Digamos que tiene una función get_everything() . Recuperará cada objeto de su base de datos en una lista. No quiere llamar a esto si el resultado será descartado, obviamente. Entonces, en lugar de usar una llamada a esa función directamente, usted define una clase interna llamada LazyGetEverything :

public class MainClass {
    private class LazyGetEverything { 
        @Override
        public String toString() { 
            return getEverything().toString(); 
        }
    }

    private Object getEverything() {
        /* returns what you want to .toString() in the inner class */
    }

    public void logEverything() {
        log.info(new LazyGetEverything());
    }
}

En este código, la llamada a getEverything() se getEverything() para que no se ejecute realmente hasta que se necesite. La función de registro ejecutará toString() en sus parámetros solo si la depuración está habilitada. De esta forma, su código sufrirá solo la sobrecarga de una llamada de función en lugar de la llamada completa getEverything() .

Answer 8

En los lenguajes que soportan las expresiones lambda o los bloques de código como parámetros, una solución para esto sería dar solo eso al método de registro. Eso podría evaluar la configuración y solo si es necesario realmente llamar / ejecutar el bloque lambda / código provisto. No lo intenté todavía, sin embargo.

En teoría, esto es posible. No me gustaría usarlo en producción debido a problemas de rendimiento que espero con el uso intensivo de lamdas / bloques de código para el registro.

Pero como siempre: si tiene dudas, pruébela y mida el impacto en la carga y la memoria de la CPU.

Answer 9

Pase el nivel de registro al registrador y déjelo decidir si escribe o no la declaración de registro:

//if(myLogger.isLoggable(Level.INFO) {myLogger.info("A String");
myLogger.info(Level.INFO,"A String");

ACTUALIZACIÓN: Ah, veo que desea crear condicionalmente la cadena de registro sin una instrucción condicional. Presumiblemente en tiempo de ejecución en lugar de tiempo de compilación.

Solo diré que la forma en que hemos resuelto esto es poner el código de formato en la clase de registrador para que el formateo solo tenga lugar si pasa el nivel. Muy similar a un sprintf incorporado. Por ejemplo:

myLogger.info(Level.INFO,"A String %d",some_number);   

Eso debería cumplir con sus criterios.

Answer 10

Por mucho que odie las macros en C / C ++, en el trabajo tenemos #defines para la parte if, que si es falso ignora (no evalúa) las siguientes expresiones, pero si true devuelve una secuencia en la que las cosas se pueden canalizar usando el '' << ''operador. Me gusta esto:

LOGGER(LEVEL_INFO) << "A String";

Supongo que esto eliminaría la ''complejidad'' adicional que su herramienta ve y también elimina cualquier cálculo de la cadena, o cualquier expresión que se registre si no se alcanzó el nivel.

Answer 11

Tal vez esto sea demasiado simple, pero ¿qué hay de usar el método de extracción de refactorización alrededor de la cláusula de guardia? Su código de ejemplo de esto:

public void Example()
{
  if(myLogger.isLoggable(Level.INFO))
      myLogger.info("A String");
  if(myLogger.isLoggable(Level.FINE))
      myLogger.fine("A more complicated String");
  // +1 for each test and log message
}

Se convierte en esto:

public void Example()
{
   _LogInfo();
   _LogFine();
   // +0 for each test and log message
}

private void _LogInfo()
{
   if(!myLogger.isLoggable(Level.INFO))
      return;

   // Do your complex argument calculations/evaluations only when needed.
}

private void _LogFine(){ /* Ditto ... */ }

Answer 12

texto alternativo http://www.scala-lang.org/sites/default/files/newsflash_logo.png

Scala tiene una annontation @elidable() que le permite eliminar métodos con un indicador de compilación.

Con la scala REPL:

C:> scala

Bienvenido a Scala versión 2.8.0.final (Java HotSpot (TM) 64-Bit Server VM, Java 1. 6.0_16). Escriba expresiones para que sean evaluadas. Escriba: ayuda para obtener más información.

scala> import scala.annotation.elidable import scala.annotation.elidable

scala> import scala.annotation.elidable._ import scala.annotation.elidable._

scala> @elidable (FINE) def logDebug (arg: String) = println (arg)

logDebug: (arg: String) Unidad

scala> logDebug ("prueba")

scala>

Con elide-beloset

C:> scala -Xelide-below 0

Bienvenido a Scala versión 2.8.0.final (Java HotSpot (TM) 64-Bit Server VM, Java 1. 6.0_16). Escriba expresiones para que sean evaluadas. Escriba: ayuda para obtener más información.

scala> import scala.annotation.elidable import scala.annotation.elidable

scala> import scala.annotation.elidable._ import scala.annotation.elidable._

scala> @elidable (FINE) def logDebug (arg: String) = println (arg)

logDebug: (arg: String) Unidad

scala> logDebug ("prueba")

pruebas

scala>

Véase también definición de afirmación de Scala