Master J2EE de Oracle: Paso 10 de 12: Masterizar el Arte de la Depuración

Puede encontrar la versión original de este artículo en Inglés en:

http://www.oracle.com/technology/pub/articles/masterj2ee/index.html

Aprenda los mecanismos programáticos para depurar aplicaciones Java y cómo utilizar la información del seguimiento de la pila para descubrir la causa raíz de los bugs.

Conquistar el Punto de Ruptura

Como arquitectos y desarrolladores de software, damos lo mejor de nosotros para entregar aplicaciones 100% libres de errores. A persar de todo, en la mayoría de las veces, los bugs se deslizan y terminan dentro de las aplicaciones liberadas. Esto es por lo que la depuración, esa tarea, algunas veces costosa, de encontrar y eliminar bugs, no se detiene cuando el software se envía al cliente, sino que muchas veces continúa después de haber liberado el software. La parte que más tiempo se lleva del proceso de depuracón es realizar el análisis de la causa raíz, encontrar la causa del bug para que se pueda resolver el problema de forma efectiva y minimizar el número de errores que envía con su código.

Una de las claves para tener éxito depurando es obtener la información desde el propio código de la aplicación, construyendo mecanismos de log, por ejemplo, que usted pueda activar y desactivar según sea necesario, para facilitar la depuración de un problema. Las aplicaciones deben diseñarse con este objetivo desde el principio, poniendo de acuerdo a los arquitectos y desarrolladores sobre las convenciones de codificación para el log, el manejo de excepciones, y otros mecanismos de captura de información y prevención de fallos. (Observe que algunas técnicas son muy útiles durante el proceso de desarrollo, pero no son apropiadas para el código de producción. Por ejemplo, puede utilizar aserciones, nuevas en J2SE 1.4, pero no habilitarlas por defecto en J2SE 5.0, para chequear condiciones anteriores y posteriores a su código, pero las aserciones no son apropiadas en código de producción).

Una estrategia de manejo de excepciones consistente puede ayudar a asegurar que sus aplicaciones generan seguimientos de pila llenos de significado (lo que le ayudaremos a hacer dentro de un minuto). Este artículo presenta varios mecanismos programáticos que usted puede utilizar para depurar aplicaciones Java. Veremos específicamente algunas de las nuevas características de J2SE 5.0, incluyendo algunos nuevos métodos del API Java, y el nuevo API Monitoring and Management que le permite entrar dentro de un agente JMX MBean de la JVM, que le permite observar todo aquello que pueda ayudarle a obtener la causa raíz de los bugs. Luego el artículo explora el modo de depurar aplicaciones Java utilizando algunos de estos mecanismos en Oracle JDeveloper 10g. Empecemos con una introducción de algunos conceptos básicos.

El Proceso de Depurado

Encontrar la causa raíz de los bugs es inherentemente difícil porque cualquier bug dado podría tener numerosas causas potenciales. Entonces, el primer paso de la depuración es reducir la complejidad y entender qué está pasando dentro de la aplicación, capturando el estado del programa en varios puntos. Entender el estado del programa a un alto nivel puede ayudar a reducir el ámbito del problema. El segundo paso es identificar al sección de código precisa que está causando el bug. El log y el seguimiento de pila de Java son dos mecanismos que se pueden utilizar juntos de forma efectiva para capturar y analizar el estado del programa.

Hacer un Log para Capturar la Información de Estado en Ficheros:

Los desarrolladores normalmente añaden sentencias println() a su código para generar información para entender la salida de error estándar mientras se está ejecutando la aplicación, para monitorizar el estado de la aplicación en tiempo de ejecución. Algunas veces las sentencias println() bien situadas también pueden ayudar durante el proceso de depuración. Aunque esta aproximación es sencilla de codificar, no es apropiada para aplicaciones desplegadas en entornos de producción, ya que la salida de la consola es temporal.

Escribir esa información a un fichero de log es una mejor opción, ya que así podrá recuperar el fichero más tarde para su análisis. En general, se pueden utilizar los logs para obtener un mejor entendimiento del estado del programa. Por ejemplo, puede registrar la entrada y salida de los métodos dentro de su código y luego buscar en los logs más tarde, para entender mejor lo que está sucediendo en su aplicación.

El marco de tabajo Java java.util.logging), y otras utilidades de log como Log4J, de la fundación Apache, proporcionan a los desarroladores unos mecanismos sencillos y configurables para escribir información de log a un fichero (en el listado 1, puede ver un ejemplo de log creado con java.util.logging). Utilizando este marco de trabajo puede cambiar fácilmente el nivel de log en los ficheros de propieades asociados, para que durante los procesos de desarrollo y depuración, el nivel de log se seleccione para una captura minuciosa, pero cuando se despliegue la aplicación, el nivel se seleccione como mínimo, para que sólo se registren los problemas reales.

Listado 1: ejemplo de log.

Sin embargo, incluso durante la fase de desarrollo usted querrá ejercer algunas restricciones en el nivel de log; ya que demasiada información puede interferir con el preceso de depurado: si los ficheros de log son demasiado verbosos será díficil leerlos enteros. Herramientas como chainsaw pueden ayudarle a filtrar una pila de ficheros de log, pero no obvian enteramente la necesidad de un uso juicioso de los niveles de log. En suma, asegurese no sólo de identificar lo que debería registrar, si no también de definir los niveles de log apropiados.

Generar Seguimientos de Pila Java

Los desarrolladores utilizan universalmente los Seguimientos de Pila Java para detectar y resolver problemas en una aplicación Java. Un Seguimiento de Pila Java es la lectura de todos los threads y monitores en una Máquina Virtual Java (JVM) en un momento particular. Todos sabemos a que se parece esto; siempre que su programa tiene un error de ejecución que usted no ha capturado en su código, se vuelca en la consola un seguimiento de pila poco ceremonioso. El seguimiento de pila proporciona información sobre todas las llamadas a métodos pendientes en un punto particular en la ejecución del programa, siguiendo hacia atrás desde la sentencia que lanzó la excepción.

Además, antes de la liberación de J2SE 5.0, se podía elegir el generar un seguimiento de pila enviando a una señal a la JVM (enviando un "kill" al proceso en Unix, o utilizando "<Ctrl><Break>" en Windows para básicamente detener la JVM en medio de la ejecución y lanzar y capturar excepciones. Ninguna de esas aproximaciones es partícularmente útil (en su objetivo de obtener información importante para facilitar la depuración), y si la aplicación no tiene una consola, o no se está ejecutando como un servicio, no sirve para nada. Y generar seguimientos de pila usando throw y cat se debe construir dentro de todas las clases necesarias en la aplicación desde el principio, durante el diseño.

Con este entendimiento básico del log y de la generación del seguimiento de pila, veamos algunas de las nuevas características de J2SE 5.0 que pueda añadir a su conjunto de herramientas de depuración.

El Nuevo API Java permite la Generación de Seguimientos de Pila tanto Estáticos como Dinámicos

Con J2SE 5.0, los desarrolladores tienen nuevos mecanismos para obtener información del seguimiento de la pila no solo más convenientemente, sino también de forma remota, específicamente nuevos métodos en el API Java (en la clase Thread, así como un nuevo API que le permite aprovecharse de la infraestructura JMX.

Un Nuevo API en J2SE 5.0 para Generar Seguimientos de Pila

J2SE 5.0 tiene dos nuevos métodos en la clase Thread que le pueden ayudar a rascar información vital de los seguimientos de pila sin la necesidad de la consola Java.

Thread.getAllStackTraces(): que devuelve un Map de todos los threads vivos en la aplicación. (Map es el interface hacia objetos StackTraceElement, que contiene el nombre del fichero, el número de línea, y el nombre de la clase y el método de la línea de código que se está ejecutando).

Thread.getStackTrace() que devuelve el seguimiento de la pila de un thread en una aplicación.

Tanto getAllStackTraces() como getStackTrace() le permiten grabar los datos del seguimiento de pila en un log, por eso no necesitará la consola. Por ejemplo, en el ejemplo mostrado en el listado 2, se necesita una consola para ver realmente el seguimiento de pila generado.

Para enviar la salida del seguimiento de pila a un fichero log (en vez de a la consola), simplemente seleccione una localización diferente en su código (en vez de System.out. Por ejemplo, podría generar un seguimiento de pila por cada petición LDAP, o para cada mensaje de log severo. Utilizar el API para hacer un log del seguimiento de la pila puede ser especialmente efectivo para obtener información contextual sobre los problemas de lógica en cuanto ocurren.

Listado 2: una clase de prueba que muestra todos los threads servidores que se están ejecutando en la JVM y muestra su seguimiento de pila:

import java.util.*;

public class StackTest {

   public void whereami() {	
      Map <Thread, StackTraceElement[]> st = Thread.getAllStackTraces();
 	 for (Map.Entry <Thread, StackTraceElement[]> e: st.entrySet()) {
	    StackTraceElement[] el = e.getValue();
	    Thread t= e.getKey();
	    System.out.println(""" + t.getName() + """ + " " +
                (t.isDaemon()?"daemon":"") + " prio=" + t.getPriority() + 
                 " Thread id=" + t.getId() + " " + t.getState());
		for (StackTraceElement line: el) {
		     System.out.println("	"+line);
		     }
			System.out.println("");
      		}
	}
    public static void main (String args[] ) {
	StackTest t1 = new StackTest();
	 t1.whereami();
	}
}

Si compila y ejecuta el programa, debería ver una salida como esta:

"Finalizer" daemon prio=8 Thread id=3 WAITING
        java.lang.Object.wait(Native Method)
        java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
        java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
        java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
 
"Reference Handler" daemon prio=10 Thread id=2 WAITING
        java.lang.Object.wait(Native Method)
        java.lang.Object.wait(Object.java:474)
        java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
 
"main"  prio=5 Thread id=1 RUNNABLE
        java.lang.Thread.dumpThreads(Native Method)
        java.lang.Thread.getAllStackTraces(Thread.java:1434)
        StackTest.whereami(StackTest.java:7)
        StackTest.main(StackTest.java:30)
 
"Signal Dispatcher" daemon prio=10 Thread id=4 RUNNABLE

Figura 1: Compilación y ejecución de la clase StackTest en Oracle JDeveloper 10g

(Anteriormente al J2SE 5.0, la clase Throwable proporcionaba (y todavía lo hace) métodos como getStackTrace() y printStackTrace(), que también son útiles en la depuración. Por ejemplo, getStackTrace() le ofrece un array de objetos StackTraceElement).

Estos nuevos métodos (Thread.getAllStackTraces(), Thread.getStackTrace()) del API Java proporcionan mecanismos estáticos para realizar seguimientos de pila desde una aplicación Java. Si el depurador lo permite, también puede generar seguimientos de pila en conjunción con puntos de ruptura para facilitar el análisis de la causa raíz. (Más adelante verá como hacer esto utilizando Oracle JDeveloper 10g.)

Sin embargo, aunque un programa funcionara, si éste no se comporta de la forma esperada, usted querrá obtener seguimientos de pila de forma dinámica, sin tener que entrar de nuevo en su código y embeber llamadas para generar logs, etc. Aquí es donde entran en juego los nuevos APIs de J2SE 5.0: Monitoring y Management.

Utilizar JMX con los Nuevos APIs Monitoring y Management de J2SE 5.0

Algunas veces es necesario generar un seguimiento de pila sin interrumpir la aplicación. Aunque se pueden generar seguimientos de pila desde fuera de la JVM utilizando RMI (se crea un interface remoto, se registra el generador de seguimientos de pila en el registro rmi y luego se le llama utilizando un cliente RMI), no tiene que meterse en lios ya que con J2SE 5.0 puede obtener dinámicamente seguimientos de pila de una forma más conveniente aprovechándose del nuevo agente JMX MBean interno de la JVM desde un cliente.

J2SE 5.0 proporciona nuevos APIs para el control y la monitorización que usan JMX como mecanismo subyacente para exponer la información de la JVM. El uso de JMX permite que la información esté disponible tanto local como remotamente para una aplicación que soporte JMX. Proporciona un conjunto de interfaces de control predefinidos que incluyen ThreadMXBean MBean (desde java.lang.management, nuevo en J2SE 5.0) y proporciona un interface de control para el subsistema Thread de la JVM.

Incluso aunque JMX está incluido en la JVM, en ésta debe habilitarse explícitamente el control externo. Abajo puede ver un ejemplo de habilitación del agente de control interno de la JVM (sin autentificación):

java -Dcom.sun.management.jmxremote.port=5001 
     -Dcom.sun.management.jmxremote.ssl=false 
     -Dcom.sun.management.jmxremote.authenticate=false  StackTest

La Figura 2 muestra estas selecciones según están configuradas en Oracle JDeveloper 10g (Preview Release)

Figura 2: Activar el server MBean (agente de control) en la JVM.

Podemos conectar con este servidor utilizando una consola JMX, o acceder a los JMX MBeans a través de un proxy. (En el ejemplo mostrado en el listado2, usamos el mismo puerto y está conectado desde la misma máquina utilizando localhost; la conexión pasa por un proxy utilizando RMI).

Listado 2: Un sencillo cliente que llama al agente JMX MBean (de la JVM) para generar dinámicamente un mapa del seguimiento de pila:

import java.lang.management.*;
import javax.management.*;
import javax.management.remote.*;

import java.util.*;

public class JMXClient {
     public static void main(String args[]) {

        ThreadMXBean t=null;
          try {
          JMXConnector connector = JMXConnectorFactory.connect( new JMXServiceURL("rmi", "",
                                   0,"/jndi/rmi://localhost:5001/jmxrmi"));

          t=java.lang.management.ManagementFactory.newPlatformMXBeanProxy(
           connector.getMBeanServerConnection(),
           java.lang.management.ManagementFactory.THREAD_MXBEAN_NAME,
         ThreadMXBean.class);

        }catch (Exception e){System.out.println(e);}
          long threads[] =t.getAllThreadIds();
          ThreadInfo[] tinfo = t.getThreadInfo(threads,5);
          for (ThreadInfo e : tinfo) {
             StackTraceElement[] el= e.getStackTrace();
             System.out.println(""" + e.getThreadName() + """ + " " + 
               " Thread id = " + e.getThreadId() + " " + e.getThreadState());
          }
     }
}

La clase ThreadInfo contiene información detallada de un thread, incluyendo el ThreadId (getThreadId()), ThreadName, y ThreadState, entre otros detalles, y proporciona el método getStackTrace() para devolver el seguimiento de pila.

También puede obtener información adicional sobre los distintos threads de la aplicación (como los threads bloqueados) para facilitar el analisis de la causa raíz.

Además de la información relacionada con los threads, también puede obtener información sobre el consumo de memoria de la JVM, lo que puede proporcionar un poco de luz sobre el estado de la JVM según se va ejecutando el programa.

JMX también se puede utilizar para controlar los niveles de log de una aplicación. Este mecanismo puede ser muy útil para generar logs concisos y concretos que ayuden a entender el estado del programa y seleccionar rápidamente los puntos de ruptura durante el seguimiento de la depuración.

Utilizar Oracle JDeveloper 10g

Con esta breve introducción a algunos de los mecanismos programáticos clave que permiten un mejor entendimiento del estado del programa para facilitar la captura de bugs, ahora veamos las capacidades de depuración de Oracle JDeveloper en conjunción con la información de log y del seguimiento de pila; para reducir el tiempo utilizado para encontrar errores en la lógica de su programa.

Un buen depurador puede facilitar el seguimiento de la depuración (el proceso de pasar a través del codigo, línea a línea, mientras se observa detenidamente el estado del programa) lo que podrá ayudarle a encontrar la causa raíz del problema. El JDK incluye un sencillo depurador (jdb, que es diferente en J2SE 5.0 de como lo era en J2SE 1.4, por eso debe revisar la documentación si quiere utilizarlo) que le permite seleccionar puntos de ruptura y pasar dentro y a través de su código.

Utilizando la información obtenida del seguimiento de pila, puede seleccionar los puntos de ruptura en las áreas adecuadas de su código, para especificar tipos de excepciones: usted selecciona un punto de ruptura para una excepción particular y luego entra en el código para encontrar donde se causó la excepción.

Las excepciones de tiempo de ejecución normalmente pueden causar comportamientos anormales en la lógica que pueden ser díficiles de localizar. Se puede utilizar el API de seguimiento de pila para registrar el estado del programa guardando el seguimiento de pila en un log. Disponer de la información del seguimiento de pila en un fichero log hace posible buscar el contexto en el que ocurrió la excepción. Este información es muy valiosa cuando se utiliza Oracle JDeveloper porque ayuda a localizar el lugar apropiado del código donde colocar un punto de ruptura.

Figura 3: Oracle JDeveloper 10g (Developer Preview) - Colocando un punto de ruptura.

Oracle JDeveloper permite seleccionar varios tipos de puntos de ruptura, como puntos de ruptura de excepción, de método y de clase. En este ejemplo, seleccionaremos un punto de ruptura de método:

Figura 4: Colocar un punto de ruptura sobre un método.

Cuando se coloca un punto de ruptura de método también es posible obtener un volcado de pila. Seleccionando el checkbox de la pestaña action (ver la Figura 5) puede ayudar a generar el volcado de pila. Cuando se entra en el método, se envía el volcado de pila a la ventana de mensajes (ver la Figura 6).

Figura 5: lanzar un seguimiento.de pila en un punto de ruptura específico.

Figura 6: Seleccionar un punto de ruptura en el código y observar la salida.

Oracle JDeveloper también proporciona mecanismos para crear puntos de ruptura de excepciones. Estos tipos de puntos de ruptura permiten a un desarrollador especificar varios tipos de excepciones, como una InterruptedException. El punto de ruptura ocurre cuando se lanza la excepción especificada. Cuando se utilizan puntos de ruptura de excepción se pueden especificar grupos de puntos de ruptura que permiten a estos grupos habilitarse y deshabilitarse como tales.

Figura 7: Seleccionar un punto de ruptura sobre un tipo de excepción específica.

Conclusión

Puede ahorrarse mucho tiempo de depuración utilizando logs para estrechar el ámbito de búsqueda dentro de la aplicación a las áreas donde puede estar el posible bug. Si diseña su aplicación desde el principio con la depuración en mente, tendrá importantes seguimientos de pila guardados en ficheros log. Utilizar el seguimiento de pila para identificar posibles áreas problemáticas puede ayudarle a imaginarse donde colocar los puntos de ruptura en su código. Las características de depuración de Oracle JDeveloper permiten a los desarrolladores utilizar la información de los seguimientos de pila para encontrar la causa raíz del comportamiento anormal dle programa.

Sin importar la herramienta especifica o la técnica, un depurador debería permitirle seleccionar no sólo puntos de ruptura en el código fuente, sino también puntos de ruptura de tiempo de ejecución, para que pueda observar la entrada y salida de un método, la carga de clases y las excepciones de tiempo de ejecución. El soporte de este tipo de características es importante porque los bugs se manifiestan por varias razones, y no todas ellas son aparentes de forma inmediata. El problema podría aparecen a partir de otros varios problemas. Además, como la mayoría de las aplicaciones complejas son distribuidas por naturaleza, una herramienta de depurado debería soportar la depuración remota. Para las aplicaciones multi-threads, un depurador no sólo debería poder visualizar threads y monitores además también debería poder hacerlo con threads bloqueados y muertos.