Dans un projet Java EE 6, j'utilise GlassFish 3.1.2.2 avec OpenJPA 2.2.2 comme implémentation JPA. Le projet étant complexe, nous utilisons un système qui nous permet de charger des classes à chaud au moyen d'un ClassLoader personnalisé. Cela fonctionne très bien sauf qu'il semblerait qu'OpenJPA fasse certaines choses bizarres conduisant aux erreurs mentionnées ci-dessous.

Afin d'isoler au mieux le(s) souci(s), j'ai créé un mini projet qui reprend toutes les problématiques rencontrées. Ce dernier est en annexe du ticket. A noter que suites à mes différents tests, j'ai ouvert un ticket sur JIRA afin d'en savoir plus. Par ailleurs j'avais également ouvert deux tickets (ici puis ) sur StackOverflow afin de chercher des idées de résolution...

Vue d'ensemble

Les projets

classloader-leak-ee
-> classloader-leak-ee-ejb
-> classloader-leak-ee-war

classloader-leak-ee-apis

Le projet apis n'est pas contenu dans l'application d'entreprise. Les classes contenues à l'intérieur de celui-ci vont être chargées dynamiquement par un simple ClassLoader.

Les classes

classloader-leak-ee-ejb
-> ch.astorm.ejb.system.ClassLoaderManager
-> ch.astorm.ejb.system.AbstractProcessor

classloader-leak-ee-apis
-> ch.astorm.apis.SimpleProcessor

Il y a quelques autres classes mais qui ne sont pas importantes dans la démonstration et l'analyse des problématiques rencontrées. Ce qui est important ici c'est que la classe ch.astorm.apis.SimpleProcessor étend ch.astorm.ejb.system.AbstractProcessor.

Les implémentations

//ch.astorm.ejb.system.ClassLoaderManager
public class ClassLoaderManager {
    private static final String PATH = "#PATH#"; //remplacé lors du clean&build dans netbeans
    private static MyClassLoader classLoader = null;
 
    public static void reset() throws MalformedURLException {
        URL[] urls = new URL[]{ new URL("file://"+PATH+"/classloader-leak-ee-apis/build/classes/") };
        classLoader = new MyClassLoader(urls, Thread.currentThread().getContextClassLoader());
    }
 
    public static Processor getProcessor() throws Exception {
        if (classLoader==null) { reset(); }
        Class<?> clazz = classLoader.loadClass("ch.astorm.apis.SimpleProcessor");
        return (Processor)clazz.newInstance();
    }
}
 
//implémentation spécifique pour pouvoir la retrouver dans le profiler
class MyClassLoader extends URLClassLoader {
    public MyClassLoader(URL[] urls, ClassLoader parent) {
        super(urls, parent);
    }
}
//ch.astorm.ejb.system.AbstractProcessor
public class AbstractProcessor implements Processor {
    @Override
    public void process(Database db, Integer id) {
        List<Person> people = db.getResultList("SELECT p FROM Person p WHERE p.id="+id);
        Person p = people.get(0);
        Integer nid = p.getId();
        System.out.print(nid);
    }
}
//ch.astorm.apis.SimpleProcessor
public class SimpleProcessor extends AbstractProcessor {
    @Override
    public void process(Database db, Integer id) {
        super.process(db, id);
    }
}

Il n'y a vraiment rien de très spécial dans ces morceaux de code. La subtilité principale réside dans le fait que ch.astorm.apis.SimpleProcessor hérite d'une classe qui est dans le ClassLoader parent, mais ça la JVM le gère très bien.

Mise en place

Pour commencer, il faut ouvrir les projets dans NetBeans (7.3.1 ou ultérieur) puis faire un Clean&Build du projet apis puis du projet principal. Une fois fait, normalement la constante PATH dans ch.astorm.ejb.system.ClassLoaderManager a du être remplacée par le chemin d'accès au projet.

Ensuite, il faut créer les données nécessaires dans MySQL:

CREATE DATABASE leaker;
USE leaker;
GRANT ALL PRIVILEGES ON leaker.* TO leaker@localhost IDENTIFIED BY 'leaker';
FLUSH PRIVILEGES;
CREATE TABLE person(id integer, shortcut varchar(255), firstname varchar(255), lastname varchar(255), comments longtext);
ALTER TABLE person ADD PRIMARY KEY (id);

Finalement, il faut déployer le projet principal sur GlassFish (clique droit > déployer). Il faut également penser à mettre le connecteur MySQL dans le dossier glassfish/domains/domain1/lib/ext de GlassFish !

Provoquer la fuite mémoire

Une fois que le projet a été déployé, il suffit d'ouvrir un navigateur et d'accéder aux URLs suivantes, l'une après l'autre:

http://localhost:8080/classloader-leak-ee-war/EPS?id=1&reset=true
http://localhost:8080/classloader-leak-ee-war/EPS?id=2&reset=false
http://localhost:8080/classloader-leak-ee-war/EPS?id=3&reset=true
http://localhost:8080/classloader-leak-ee-war/EPS?id=4&reset=false
http://localhost:8080/classloader-leak-ee-war/EPS?id=5&reset=true
http://localhost:8080/classloader-leak-ee-war/EPS?id=6&reset=false
http://localhost:8080/classloader-leak-ee-war/EPS?id=7&reset=true
http://localhost:8080/classloader-leak-ee-war/EPS?id=8&reset=false

Pour les linuxiens, il est possible d'utiliser le script leak.sh qui va faire cela pour vous.

Analyser la fuite

C'est maintenant que les choses deviennent intéressantes. Grâce à VisualVM il est possible de faire un dump du tas (heap dump) de l'instance GlassFish en train de tourner afin de voir quels sont les objets instanciés. Et si on fait une recherche de MyClassLoader, voici ce qui est obtenu: leak-analysis.png

On constate qu'il y a 4 instances de MyClassLoader alors qu'il ne devrait y en avoir qu'une ! Déjà là, c'est une première surprise et cela indique clairement qu'il y a une fuite mémoire quelque part car le ClassLoaderManager ne retient une référence que sur la dernière instance. Si on regarde la dernière instance, on voit bien qu'effectivement il y a une référence: leak-GC-root.png

Ce qu'il faut savoir, c'est que toutes les classes instanciées au sein d'un ClassLoader gardent une référence sur ce dernier. Donc, il suffit de voir où se situe cette référence pour comprendre pourquoi les autres instances de MyClassLoader n'ont pas été supprimmées par le Garbage Collector. Donc, de la même manière dans VisualVM, on recherche les racines au GC: leak-no-GC-root.png

Et c'est là que ça fait mal: VisualVM indique qu'il n'y a pas de racine au GC et donc que ce dernier est censé supprimer ces instances !!! Malheureusement, et ce malgré des appels multiples à System.gc() afin de forcer une collecte complète, ces classes ne sont jamais supprimées ! C'est là qu'au bout d'un moment on tombe sur la fameuse erreur java.lang.OutOfMemoryError: PermGen space.

J'ai testé plusieurs analyseurs et tous sont formels: il n'y a pas de référence sur les autres instances du MyClassLoader, par conséquent il n'est pas censé y avoir de fuite mémoire ! Le fait est qu'il y en a clairement une et que je ne dispose d'aucun moyen pour savoir exactement d'où ça vient... Un chouette Bohr bug :-)

Résolution

Arriver à extraire le bug de l'application originale pour le reproduire dans ce petit projet fut déjà une étape compliquée. J'ai ensuite testé pas mal de choses et je suis tombé sur des comportements très surprenants. Dans les chapitres suivants, je vais faire une ou plusieurs modifications et analyser le résultat. Pour chacun des tests, j'utilise toujours le projet original.

A noter que les tests sont fastidieux car il est nécessaire de supprimer (undeploy) l'application de GlassFish, arrêter ce dernier, recompiler le tout, redéployer le projet principal et enfin refaire toutes les requêtes. Sans oublier qu'il faut encore refaire un dump mémoire ainsi que l'analyse.

Test 1: paramétrisation des prédicats

La modification est très simple: plutôt que d'utiliser la ligne suivante dans ch.astorm.ejb.system.AbstractProcessor:

List<Person> people = db.getResultList("SELECT p FROM Person p WHERE p.id="+id);

je la remplace par:

List<Person> people = db.getResultList("SELECT p FROM Person p WHERE p.id=?1", id);

En arrière-plan, la classe Database va utiliser la fonction Query.setParameter() pour définir la valeur de ce dernier, dénoté avec la syntaxe ?1.

J'ai testé cette modification dans deux situations: l'originale (le ClassLoader est recréé une fois sur deux) et en le recréant à chaque fois. Dans les deux cas, il y a une nette amélioration: il n'y a plus que deux instances de MyClassLoader, dont une n'a pas de référence. Cette solution permet donc de résoudre partiellement la fuite mémoire. Ceci dit, cela est surprenant car il n'y a aucune contre-indication (si ce n'est l'injection SQL) de mettre le prédicat directement dans la requête...

Test 2: Utiliser EclipseLink

Afin d'isoler le problème, j'ai utilisé EclipseLink plutôt qu'OpenJPA (voir le fichier persistence.xml). Et la bonne nouvelle est que cela semble résoudre complètement le souci: cette fois je n'ai bien qu'une seule instance de MyClassLoader ! Il y aurait donc effectivement quelque chose dans OpenJPA qui provoque cette fuite...

Test 3: Eviter l'override

J'ai simplement commenté la méthode process() dans la classe ch.astorm.apis.SimpleProcessor. Après avoir refait les tests (plusieurs fois), force m'est de constater que cela corrige la fuite (exactement comme le test 2) ! Je dois admettre que je n'ai aucune idée de ce qui peut provoquer cela... Est-ce que ce serait une manipulation d'OpenJPA qui provoque un bug dans la JVM elle-même ? Cela me conduit à mon prochain test.

Test 4: Passer par une méthode final

J'ai modifié ch.astorm.ejb.system.AbstractProcessor pour ajouter une nouvelle méthode avec le modifier final afin qu'elle ne puisse pas être écrasée. Cette nouvelle méthode fait un appel simple à process().

Malheureusement, ce changement n'apporte aucune amélioration et je me retrouve toujours avec mes 4 instances...

Test 5: Tout charger dynamiquement

Pour cela, il suffit de déplacer la classe ch.astorm.ejb.system.AbstractProcessor dans ch.astorm.apis. Cette modification n'ayant apporté aucun changement (toujours 4 instances), j'ai approfondi le test en re-commentant la méthode écrasée comme au point (3). Par contre cette fois, aucun changement de résultat, il y a de nouveau 4 instances alors qu'avant cela corrigeait le problème...

Autres tests

J'en ai fait plusieurs autres, malheureusement aucun d'eux ne permet de résoudre le souci, même partiellement. Les intéressés peuvent voir le README dans le projet annexé. Par ailleurs, je suis également tombé sur le message d'erreur suivant:

LDR5207: ASURLClassLoader EarLibClassLoader : 
doneCalled = true
doneSnapshot = ASURLClassLoader.done() called ON EarLibClassLoader : 
urlSet = [...]
doneCalled = false 
 Parent -> org.glassfish.internal.api.DelegatingClassLoader@1bf1a64c

 AT Thu Nov 14 09:06:44 CET 2013 
 BY :java.lang.Throwable: printStackTraceToString
        at com.sun.enterprise.util.Print.printStackTraceToString(Print.java:639)
        at com.sun.enterprise.loader.ASURLClassLoader.done(ASURLClassLoader.java:211)
        at com.sun.enterprise.loader.ASURLClassLoader.preDestroy(ASURLClassLoader.java:179)
        at org.glassfish.javaee.full.deployment.EarClassLoader.preDestroy(EarClassLoader.java:114)
        at org.glassfish.deployment.common.DeploymentContextImpl.getClassLoader(DeploymentContextImpl.java:236)
        at org.glassfish.deployment.common.DeploymentContextImpl.getClassLoader(DeploymentContextImpl.java:186)
        at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:450)
        ...
 Parent -> org.glassfish.internal.api.DelegatingClassLoader@1bf1a64c
 was requested to find class org.apache.openjpa.lib.util.concurrent.ConcurrentReferenceHashMap$SoftEntry after done was invoked from the following stack trace
java.lang.Throwable (com.sun.enterprise.loader.ASURLClassLoader in method findClassData at line 780)

Cela venait du fait que certaines requêtes utilisaient des prédicats non paramétrés. Ce qui est bizarre, c'est que le code fonctionne bien quelque temps et tout d'un coup, le ClassLoader change et certaines classes sont "perdues".

Conclusion

A ce jour, je ne peux que constater les choses suivantes:

  • Toujours utiliser des prédicats paramétrés (aussi pour éviter les injections)
  • Préférer EclipseLink (éventuellement Hibernate ?)