Sistemas de Trazas
domingo, enero 26, 2003 at 1:00AM
Sistemas de Trazas
Fecha de creación: 12.01.2003
Revisión 1.0 (25.03.2003)
Enrique Rodriguez Lasterra
lasterra_ARROBA_javahispano.org
|
Introducción
Quien no ha puesto un System.out.println para escribir en la consola
el valor de una variable? Y el típico mensaje ?llega aquí?????. Sin
duda alguna, esta es la forma más sencilla y más utilizada de depurar
nuestro código.
En base a esta idea se han ido creando sistemas de gestión de
logs/trazas que han ido añadiendo diversas funcionalidades demandadas
por los programadores.
Este articulo intenta explicar como utilizar los mas conocidos,
Jakarta-Log4j, el nuevo paquete de la JDK1.4 java.util.logging y
Jakarta-Commons-Logging.
Jakarta-Log4j
Jakarta-Log4j es una de las más antiguas, potentes y conocidas.
Entre sus características principales se encuentran:
Diferentes niveles de traza. (Error, información,
depurar.)- Filtros según categoría
Redirección de las trazas a diferentes destinos.
(A un archivo, a consola, a BBDD.)
Diferentes formatos de visualización. (Visualizar fecha,
línea, nombre de la clase..)- Configuración por ficheros
Vamos a ir descubriendo estas características paso a paso:
Niveles de Prioridad de Traza
Log4j provee al programador de 5 niveles de traza:
- OFF, no se muestra en ningún caso
FATAL, para mostrar mensajes de situaciones que
probablemente harán abortar la aplicación
ERROR, para mostrar mensajes de errores que no son
deseados pero que no interrumpirán la aplicación
WARN, para mostrar mensajes de contextos peligros para
la aplicación, o ciertas operaciones de uso no recomendado
INFO, para mostrar mensajes de información sobre la
ejecución de la aplicación, o eventos importantes dentro
de la misma
DEBUG, para mostrar mensajes interesantes para depurar
la aplicación. Muy orientado al tiempo de desarrollo- ALL, se muestra en todos los casos
Cuando escribimos nuestras aplicaciones, las trazas se
escriben en los diferentes niveles dependiendo de la
operación que se utilice. Así para escribir en el nivel INFO
se usa log.info("Nivel Info"); y para el nivel DEBUG
log.debug("Nivel Debug").
Por lo general el nivel de prioridad esta fijado por defecto
a INFO, por lo que los mensajes de nivel DEBUG no son visualizados.
Este nivel genera un caudal elevado de trazas por lo que su
uso suele estar restringido a entornos de desarrollo.
Un apartado importante en el uso de las trazas es como utilizarlas cuando se producen errores/excepciones. No siempre hay que escribir las trazas de excepciones a nivel de error, ya que en algunos casos no interesa que se visualicen.
En caso de escribir componentes que posteriormente utilicen otras personas, convendra relanzar la excepción y escribir la traza a nivel de DEBUG o INFO dependiendo de si el programador sera el propio usuario de la clase o si un tercero sera quien la utilice.
Categorías (ó como filtrar las trazas)
Para ver esta característica es necesario adentrarse un poco más en la configuración y el código necesario para trabajar con Log4j. En el siguiente ejemplo se muestra como tracear una clase.
import org.apache.log4j.*
public class Pruebaslog4j {
Logger log = Logger.getLogger(this.getClass());
/** Creates a new instance of Pruebaslog4j */
public Pruebaslog4j () {
try {
log.info("Constructor");
log.warn("nivel WARN");
if (log.isDebugEnabled()) {
log.debug("Traza de nivel debug");
}
} catch (IllegalStateException e) {
log.error("Traza de nivel error", e);
}
}
/**
* @param args the command line arguments
*/
public static void main(String[] args) {
Pruebaslog4j pl4j = new Pruebaslog4j ();
}
}
En la segunda línea se obtiene el objeto con el cual se escriben las trazas, el objeto Logger. Se puede hacer referencia a este objeto bajo el nombre "escritor", ya que es el quien se encarga de escribir los mensajes a los diferentes soportes con los cuales Log4j trabaja.
Para obtener este objeto se le pasa la clase, o el nombre completo de la clase, es decir, paquete.otropaquete.NombreClase, o cualquier otro nombre con el que se defina la categoría de esta traza.
Una categoría suele ser el nombre completo de la clase, ya que normalmente, las aplicaciones se dividen en diversos paquetes. También, si un componente utiliza más de un paquete es común definir la categoría con el nombre del componente, para tratar de la misma forma las trazas escritas en los dos paquetes.
Se puede jerarquizar las categorías, separando los niveles con "."(Puntos). Por tanto si se define la categoría con el nombre componente.primario, primario es una categoría hija de componente. Como veremos mas adelante, las configuraciones que se asocien a componente serán heredadas por primario. Estas configuraciones se realizan en el archivo de configuración.
Archivo de configuración
Log4j se puede configurar desde un archivo XML o desde un archivo de propiedades. Empecemos por la mas antigua y sencilla, el archivo de propiedades.
Para configurar Log4j de esta forma es necesario que el archivo log4j.properties este en el CLASSPATH de nuestra aplicación. Esto quiere decir que tiene que estar en la raíz de nuestro código, o dentro de algún archivo JAR que nuestra aplicación cargue, o al lanzar el programa, fijando la propiedad del sistema con el argumento
java Clase -Dlog4j.configuration=log4j.properties
Este archivo comienza con la configuración del nivel principal de la jerarquía, el ROOT. Bajo este nivel se encuentran todas las categorías de nuestra aplicación. Para configurar el nivel ROOT hay que escribir en el fichero de propiedades la propiedad log4j.rootLogger e igualarla al nivel de prioridad que por defecto se desea fijar. Tras el nivel de prioridad, separados entre comas, los diferentes appenders a los que por defecto se desean redireccionar nuestras trazas. (Aprenders??? la explicación un poco más abajo, paciencia ;-)
log4j.rootLogger=DEBUG, Consola, Fichero
En el ejemplo fijamos el nivel por defecto a DEBUG (muy típico cuando estamos desarrollando el código) y redireccionamos a los appenders Consola y Fichero.
Ya tenemos todo nuestro código fijado con un nivel de trazas DEBUG. En muchos casos, no nos interesa ver todas las trazas de una aplicación, por ejemplo, cuando se utiliza un componente cuyo funcionamiento ya ha sido probado. Para subir el nivel de traza a INFO o WARN en dicho componente escribimos la siguiente propiedad en el fichero de configuración.
log4j.Logger.NombreCategoria=INFO
O si se utiliza como nombre de categoría la ruta completa a las clases
log4j.Logger.com.empresa.componente=INFO
Cuando se realiza esta operación, decimos que la categoría tiene un nivel de traza fijado de forma explicita. Esto hace que el paquete "com.empresa.componente" tenga el nivel de traza fijado a INFO, o lo que es lo mismo, no se escribirá ninguna traza de nivel DEBUG dentro de ese paquete. Si el componente tiene subpaquetes, y estos no tienen un nivel de traza fijado de forma explicita, heredan el nivel de traza del paquete que los contiene.
Visto al revés, si un paquete no tiene asignado de forma explicita un nivel de prioridad de traza, el paquete obtiene el nivel del paquete en el que esta contenido. Así de forma recursiva, hasta que se encuentre con un paquete con nivel de traza asignado de forma explicita o con el nivel principal de la jerarquía, con ROOT.
A continuación 3 ejemplos que visualizan el comportamiento de herencia anteriormente descrito. (Fijaros en la última columna)
|
|
|
| root | DEBUG | DEBUG |
| X | ninguno | DEBUG |
| X.Y | ninguno | DEBUG |
| X.Y.Z | ninguno | DEBUG |
|
|
|
| root | DEBUG | DEBUG |
| X | WARN | WARN |
| X.Y | INFO | INFO |
| X.Y.Z | DEBUG | DEBUG |
|
|
|
| root | DEBUG | DEBUG |
| X | ninguno | DEBUG |
| X.Y | ninguno | DEBUG |
| X.Y.Z | INFO | INFO |
Appenders
Una vez establecido el nivel de trazas de nuestro código hay que configurar donde queremos que nuestras trazas sean escritas o direccionadas. Las opciones más utilizadas son a la consola y los archivos de texto, pero Log4j también puede escribir las trazas en base de datos, en una cola de mensajes JMS o en el visor de sucesos de Microsoft Windows.
Veamos como se configurarían los appenders:
Lo primero de todo es definir los nombre de los appenders que se van a utilizar en la propiedad log4j.rootLogger. Recordad que en esta propiedad se fijaba el nivel de traza por defecto y seguido y separados por coma, el nombre de los appenders que se van a usar. Al fijar estos appenders en la categoría principal, todas las trazas de la aplicación serán direccionadas a ellos
log4j.rootLogger=DEBUG, Consola, Fichero
Si se quiere que alguna categoría en concreto sea direccionada a otro appender, definiremos para esa categoría su appender
log4j.Logger.categoriaComponente=INFO, FicheroComponente
Si se realiza este tipo de configuración hay que tener en cuenta que los appenders por defecto son heredados. Log4j utiliza para hablar de esta propiedad el termino "additivity" de appenders.
Para el ejemplo anterior, las trazas escritas para la categoría categoriaComponente, serán direccionadas al appender FicheroComponente, Fichero y Consola, ya que Fichero y Consola son heredados por defecto desde la categoría ROOT.
Si no se desea heredar los appenders, hay que definir la siguiente propiedad en el fichero de configuración:
log4j.logger.append.categoriaComponente=false
Solo queda configurar cada uno de ellos.
Configurar el ConsoleAppender
Para configurar el aprender Consola, lo primero que hay que decirle es el tipo de aprender que es, en este caso de consola, por lo que hay que escribir la siguiente propiedad
log4j.appender.Consola=org.apache.log4j.ConsoleAppender
Lo siguiente será configurar el nivel de traza, ya que cada aprender puede tener uno distinto. Por ejemplo, es bastante común poner la salida a fichero con nivel DEBUG y la salida de consola con nivel INFO.
log4j.appender.Consola.Threshold=INFO
Para acabar con la configuración de la salida, asignamos el appender a un stream. Ya que lo que se busca es escribir en consola, se fija la salida a System.out.
log4j.appender.Consola.Target=System.out
La configuración de un appender para fichero sería muy parecida. Primero se le dice al appender que es de tipo fichero. Existen varios tipos de appender a fichero, los más comunes son RollingFileAppender y DailyRollingFileAppender
El primero escribe las trazas en un fichero de tamaño máximo configurable. Cuando se llega a ese tamaño, el fichero se renombra a nombreFichero.ext.1, y se continúan escribiendo las trazas en un nuevo fichero nombreFichero.ext.
Cuando este llegue a su tamaño máximo se renombrara a nombreFichero.ext.1 y el que era nombreFichero.ext.1 pasa a ser nombreFichero.ext.2. Así continuamente, van "rotando" los ficheros, de hay su nombre de RollingFileAppender. En caso de que se llegue al número máximo de ficheros, se borrara el fichero más antiguo.
- El segundo escribe las trazas en un fichero diario, al acabar el día, Log4j crea un nuevo fichero
Configurar un RollingFileAppender
Como siempre le decimos al appender de que tipo es
log4j.appender.Fichero= org.apache.log4j.RollingFileAppender
Le decimos la ruta donde se va a crear el fichero, tomando como raíz el lugar donde se encuentre el fichero. También se puede utilizar una ruta completa (c://log/trazas.log o en UNIX /usr/log/trazas.log)
log4j.appender.Fichero.File=./log/Trazas.log
* Me llevo bastante mal con esta propiedad, muchas veces me veo obligado a escribir la ruta completa para que las trazas se escriban en el fichero.
Por ultimo configuramos el tamaño máximo del fichero, y el número máximo de ficheros que van a rotar.
log4j.appender.Fichero.MaxFileSize=500KB
log4j.appender.Fichero.MaxBackupIndex=10
Con esta configuración tendremos 5 megas de trazas.
Otros Appenders
Con los ejemplos anteriores se muestra la facilidad para configurar los appenders. Log4j tiene multiples appenders a los cuales redireccionar las trazas, ejemplo de configuración básicos serian los siguentes:
JDBCAppender
#Como siempre tipo de appender
log4j.appender.appenderBD=org.apache.log4j.jdbc.JDBCAppender
#url a la base de datos, en este caso ejemplo para mysql
log4j.appender.appenderBD.URL=jdbc:mysql://javahispano/Log4j
#usuario y password de la base de datos
log4j.appender.appenderBD.user=java
log4j.appender.appenderBD.password=hispano
#isntrucción SQL a la que se va a llamar
log4j.appender.appenderBD.sql=INSERT INTO Tabla (fecha,mensaje)
VALUES ('%d','%c - %p - %m')
SMTPAppender
log4j.appender.appenderCorreo.To =drafts@javahispano.org
log4j.appender.appenderCorreo.From =lasterra@javahispano.org
log4j.appender.appenderCorreo.Subject =Error Enviado desde Log4j
#Si el servidor requiere autentificación no funcionara :-(
log4j.appender.appenderCorreo.SMTPHost=smtp.javahispano.org //or ip-Adress
log4j.appender.appenderCorreo.BufferSize=1
Layouts
Este es el último de los elementos configurables, la forma y la información que se escribe en cada traza. A cada appender se le puede añadir un layout. El más común es el PatternLayout, en el cual se configuran una serie de variables, es decir, el patrón, que se cambiaran en el momento de escribir en el appender. Mas claro con un ejemplo
log4j.appender.Consola.layout =PatternLayout
log4j.appender.Consola.layout.ConversionPattern= %d [%p,%c] %m %n
Con ese patrón se visualizaría
Hora [Prioridad de la traza, categoria] El mensaje de la traza Salto de línea
Un ejemplo
11:55:48,755 [DEBUG,org.javahispano.articulo] Mensaje de nivel DEBUG
Otras opciones que admite el patrón son
- %F: Nombre del fichero. (Operación muy costosa)
- %l: Número de línea. (Operación muy costosa)
- %d{ISO8601}: Fecha en el estándar ISO 8601 (2003-01-12 17:26:30,234)
- %d{HH:mm:ss,SSS}: Fecha con la misma sintaxis del SimpleDateFormat
- %r: Milisegundos desde que comenzó el programa
- %t: Hilo que llamo al Logger.
Más información en: [PatternLayout]
Configurando en XML
Todo lo anteriormente explicado para la configuración de Log4j con el archivo de propiedades log4j.propierties se puede aplicar a la configuración en xml del archivo log4j.xml
Como se ve a continuación, primero se configuran los diferentes appenders, posteriormente se van configurando aquellas categorías a las cuales se les desea efectuar un tratamiento especial, y por ultimo la categoría ROOT.
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
<appender name="Fichero" class="org.apache.log4j.FileAppender">
<param name="File" value="A1.log" />
<param name="Append" value="false" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%t %-5p %c{2} - %m%n"/>
</layout>
</appender>
<appender name="Consola" class="org.apache.log4j.ConsoleAppender">
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern"
value="%d %-5p [%t] %C{2} (%F:%L) - %m%n"/>
</layout>
</appender>
<category name="nombreCategoria">
<priority value="debug" />
<appender-ref ref="Fichero" />
</category>
<root>
<priority value ="debug" />
<appender-ref ref="Consola" />
</root>
</log4j:configuration>
Rendimiento
Log 4j se ha construido intentando lograr el mayor rendimiento posible. El peso de añadir una traza dentro del programa ralentiza su ejecución entre 5 y 50 nanosegundos cuando esta deshabilitada. Si esta habilitada depende del tipo de appender y del layout.
La mayor parte de este tiempo se gasta en construir el String del mensaje. Para evitar este tiempo Log4j tiene las operaciones Logger.isDebugEnabled() Logger.isInfoEnabled, etc.
Gracias a estas operaciones, y añadiendo una condición en el código, podemos ahorrar bastante tiempo a cambio de escribir la condición. Si la velocidad es un aspecto crítico para la aplicación hay que considerar la necesidad de introducir este recurso.
java.util.logging
El nuevo paquete introducido en la JDK1.4 es muy similar al anterior sistema descrito.
El código de las aplicaciones es muy similar, ya que también se utiliza en objeto Logger para escribir las trazas. La definición de los niveles es la siguiente
- SEVERE (valor mas alto)
- WARNING
- INFO
- CONFIG
- FINE
- FINER
- FINEST (valor mas bajo)
En vez de appender, este sistema de logging habla de "handlers" (manejadores). La J2SE viene con 5 tipos de handlers:
- Stream
- Console
- File
- Socket
- Memory
De entre todos estos, es el último el que no esta dentro de la distribución de Log4j
A cada handler, al igual que a los appenders de Log4j, se le puede asociar un formato. O bien la traza es un simple String con el mensaje, SimpleFormatter. O bien esta definida en XML, XMLFormatter. Un ejemplo de este último sería:
<record>
<date>2000-08-23 19:21:05</date>
<millis>967083665789</millis>
<sequence>1256</sequence>
<logger>kgh.test.fred</logger>
<level>INFO</level>
<class>kgh.test.XMLTest</class>
<method>writeLog</method>
<thread>10</thread>
<message>Hello world!</message>
</record>
El fichero de configuración viene incluido dentro del JRE.< Directorio _ JRE >/lib/logging.properties.
En el se configuran los handlers que se van a utilizar, asignando a la propiedad handlers los handlers separados por coma
handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler
La configuración de cada handler, primero el lugar donde se van a generar los Logs
java.util.logging.FileHandler.pattern = %h/java%u.log
- "/" El separador del sistema
- "%t" El directorio temporal
- "%h" el directorio del usuario (Mis documentos o /usr/home)
- "%g" numero generado para distinguir la rotacion de ficheros
- "%u" numero unico para resolver posibles conflictos
Tamaño maximo del fichero
java.util.logging.FileHandler.limit = 50000
Numero de archivos del ciclo de rotación
java.util.logging.FileHandler.count = 1
Formato de escritura
java.util.logging.FileHandler.formatter = java.util.logging.XMLFormatter
Tambien se puede configurar un nivel de salida. Como ejemplo se muestra esta configuración en el ConsoleHandler
java.util.logging.ConsoleHandler.level = INFO
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
El nivel por defecto
.level=INFO
Se pueden definir diferentes niveles de salida para cada paquete, en java.util.logging no se puede hablar del concepto de categoría.
com.xyz.foo.level = SEVERE
Si en vez de modificar este archivo, queremos configrar nuestra aplicación con otro, al lanzar la aplicación le debemos decir donde se encuentra dicho archivo de la siguiente forma:
java -Djava.util.logging.config.file=rutaAMiarchivo
Jakarta-Commons-Logging (JCL)
En vista de que son varios los sistemas de trazas que actualmente se pueden elegir, bajo el proyecto commons de Jakarta, se ha creado un pequeño subproyecto gracias a el cual se puede intercambiar de un sistema de trazas a otro sin tener que cambiar ni una línea de código.
JCL provee de clases e interfaces que se encargan de llamar a las clases de los verdaderos sistemas de trazas. Por defecto, si las clases de log4j están en el CLASSPATH de la aplicación, serán a ellas a quien se direccione la llamada.
Si estas no son localizadas, y se esta trabajando con la JDK1.4, se realizan llamadas a las clases del paquete java.util.logging.
Y si no el propio JCL las direcciona todas las trazas a System.err.
Para usar JCL solo hay que hacer dos cosas
- Añadir JCL al CLASSPATH de tu aplicación
- Escribir en tu codigo las sentencias de JCL en vez de las de otro sistema de trazas
Por lo tanto, una vez JCL esta en nuestro CLASSPATH, debemos importar las clases que necesitamos
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
Obtener el Log, conocido como Logger en Log4j y java.util.logging
Log log = LogFactory.getLog(this.getClass());
Escribir las trazas igual que en los sistemas anteriormente explicados
if (log.isDebugEnabled())
log.debug("mensaje");
Gracias a ese pequeño cambio, podemos usar Log4j, java.util.logging u otro sistema de trazas sin tener que cambiar el código.
Hacer uso de JCL es recomendable si:
- Estas programando clases que utilizara otro programador
- Utilizas diferentes sistemas de trazas según el proyecto en el que trabajas
- Programas clases que se usaran en otros proyectos y/o entornos
- No tienes muy claro que sistemas de trazas usar
Conclusión
Este artículo muestra los sistemas de trazas mas conocidos. Se puede extraer de la lectura que java.util.logging es una copia de Log4j, con algunas opciones menos pero con la garantía de que va incluido en la JDK.
Para mi no hay dudas, Log4j y JCL es la mejor combinación, pero el gusto y la confianza en los productos Open Source harán que cada uno elija la combinación que mas le guste.
En cualquier caso, cualquiera es mejor que utilizar System.out y me aventuro a decir que mejor que cualquier sistema propio que se haya podido crear.
Recursos
[1] Jakarta-Log4j,
http://jakarta.apache.org/log4j/
[2] Ultima versión Log4j,
http://jakarta.apache.org/log4j/docs/download.html
[PatternLayout] API PatternLayout,
http://jakarta.apache.org/log4j/docs/api/org/apache/log4j/PatternLayout.html
[3] Java logging overview,
http://java.sun.com/j2se/1.4.1/docs/guide/util/logging/overview.html
[4] Jakarta-Commons-Logging,
http://jakarta.apache.org/commons/logging/index.html
[5] Versiones JCL,
http://jakarta.apache.org/builds/jakarta-commons/release/commons-logging/
[6] JCL user guide,
http://cvs.apache.org/viewcvs.cgi/*checkout*/jakarta-commons/logging/usersguide.html?rev=HEAD
[7]
The complete log4j manual,
Ceki Gulcu
Acerca del autor
Enrique Rodriguez Lasterra
Informático de nacimiento y a un paso de licenciarse como ingeniero
por la Universidad de Deusto.Trabaja en la empresa bilbaína
NHT-Norwick.com desde hace ya mas de dos años donde programa, como
no, en Java.
Reader Comments