La Cara Oscura
del Desarrollo de Software

Tenemos un par de días experimentando un pequeño incoveniente con una aplicación Web a la que le estamos haciendo unos enhacements. El inconveniente solo ocurre (por supuesto) en la instalación de nuestro cliente.

El punto es que ciertos archivos de log no están siendo generados por la aplicación Web.

Para el logging de nuestras aplicaciones usamos log4j (excelente librería). El problema en cuestión no podíamos reproducirlo en nuestros servidores, así que despues de mucho excavar (por correo y teléfono) en la configuración del servidor de aplicaciones de nuestro cliente, nos damos cuenta que en el directorio /lib del servidor de aplicaciones hay otro jar de log4j distinto al que tiene la aplicación Web en su directorio /WEB-INF/lib. Es decir, las clases que se estaban cargando eran las del jar que está ubicado en el directorio /lib del contenedor y no las que están en el jar ubicado en el directorio WEB-INF/lib de nuestra aplicación, con lo cual la inicialización "a-la-medida" que hacemos de log4j no funcionaba, por ende no se generaban los archivos de log necesarios.

¿Y por que ocurre esto? Por la forma en que funcionan los Classloaders. Los classloaders son los responsables de cargar las clases dentro de la JVM. Existen tres classloaders por defecto, los cuales mantienen una jerarquía de delegación.

Primero está el Bootstrap Classloader, este classloader es nativo a cada ambiente y NO está escrito en Java (el resto de los classloaders es implementado en Java). Su principal función es cargar las clases del core de Java (ej: java.util.*), y además cargar el resto de los classloaders, el Extension Classloader y el Application Classloader.

El Extension Classloader se encarga de cargar las clases que extienden el core de Java (ej: en Java 1.3 sería el javax.*) y de todas las clases que esten en el directorio /ext del runtime de Java. Mientras que el Application Loader se encarga de cargar las clases de la aplicación en cuestión.

Estos classloaders siguen un patrón de delegación, cuando la aplicación requiere una clase, esta se la solicita al application classloader, este delega esta tarea al extension classloader, y este a su vez al bootstrap classloader. Si el bootstrap classloader consigue la clase (ej: una clase del core de Java) la hace disponible, en caso contrario, devuelve el requerimiento al extension classloader, si este a su vez no consigue la clase, devuelve el requerimiento al application classloader. Es decir, la idea es que cada classloader primero interroga a su padre, solo en el caso en que el padre no consiga la clase, es que el classloader intenta buscarla por si mismo.

En los servidores de aplicación J2EE el funcionamiento es similar, aqui cada aplicación "montada" como un archivo EAR tiene su propio classloader, el cual es hijo del application classloader (que se mencionó antes). Este classloader es el encargado de cargar las clases usadas por los EJBs y WebApps empotradas en el EAR.

Es por esta razón que en nuestro caso en la instalación del cliente las clases de log4j que se cargaban eran las que estaban en el directorio /lib del servidor J2EE y no las que estaban en el directorio /WEB-INF/lib de nuestra aplicación.

Ahora bien la forma que usamos para demostrar que esto efectivamente era asi, fue haciendo lo siguiente, cambiamos la forma como incializamos log4j y luego agregamos esta información de debug:

Es decir, escribir al log cual es la versión de log4j que se está usando. Y en el log apareció reportada la versión del log4j que está en el directorio /lib del servidor J2EE y no la del log4j que está en el directorio /WEB-INF/lib de la aplicación.

Un aspecto importante aqui es que el método getImplementationVersion() no funciona para todos las librerías, solo para aquellas que tienen la buena práctica de crear un archivo META-INF/MANIFEST.MF como se debe:

Otro punto importante del código es que no todos los classloaders crean un objeto Package, un ejemplo de esto es el classloader que usa Maven para correr los TestCases (JUnit), de hecho el método getPackage() me devolvió null al ejecutar el TestCase.