Mise en place

J'utilise NetBeans 7.4 avec un Glassfish 3.1.2.2 et un MySQL 5.1. J'ai une entité tout simple qui a la forme suivante:

@Entity
@Table(name = "person")
public class Person implements Serializable {
    @Column
    @Id
    private Integer id;
 
    @Column
    private String shortcut;
 
    @Column
    private String firstname;
 
    @Column
    private String lastname;
 
    public Person() {}
    public Person(Integer id, String shortcut, String firstname, String lastname) {
        this.id = id;
        this.shortcut = shortcut;
        this.firstname = firstname;
        this.lastname = lastname;
    }
 
    public Integer getId() { return id; }
    public void setId(Integer id) { this.id = id; }
 
    public String getShortcut() { return shortcut; }
    public void setShortcut(String shortcut) { this.shortcut = shortcut; }
 
    public String getFirstname() { return firstname; }
    public void setFirstname(String firstname) { this.firstname = firstname; }
 
    public String getLastname() { return lastname; }
    public void setLastname(String lastname) { this.lastname = lastname; }
}

Dans mon code, tout ce que je fais est de créer une nouvelle entité, puis de la récupérer au moyen d'une requête dynamique:

Integer maxId = (Integer)entityManager.createQuery("SELECT MAX(p.id) FROM Person p").getSingleResult();
if (maxId==null) { maxId = 0; }
 
Integer pid = maxId+1;
Person np = new Person(pid, null, name, firstname);
entityManager.persist(np);
 
Person p = (Person)entityManager.createQuery("SELECT p FROM Person p WHERE p.id="+pid).getSingleResult();
//...

Provoquer l'erreur

Une fois déployé, l'erreur est assez simple à provoquer. J'ai fait un petit script qui appelle la requête suivante avec curl:

curl "http://localhost:8080/classloader-leak-ee-war/EPS?action=insert&name=${name}&firstname=${firstname}"

En laissant tourner un petit moment le script (jusqu'a environ la 1000ème insertion), le serveur se met subitement à paniquer et à renvoyer l'erreur suivante

Caused by: java.lang.NoClassDefFoundError: org/apache/openjpa/lib/util/concurrent/ConcurrentReferenceHashMap$SoftEntry
at org.apache.openjpa.lib.util.concurrent.ConcurrentReferenceHashMap.newEntry(ConcurrentReferenceHashMap.java:402)
at org.apache.openjpa.lib.util.concurrent.ConcurrentReferenceHashMap.put(ConcurrentReferenceHashMap.java:386)
at org.apache.openjpa.util.CacheMap.put(CacheMap.java:174)
at org.apache.openjpa.util.CacheMap.cacheMapOverflowRemoved(CacheMap.java:150)
at org.apache.openjpa.util.CacheMap$2.overflowRemoved(CacheMap.java:128)
at org.apache.openjpa.lib.util.concurrent.ConcurrentHashMap.removeOverflow(ConcurrentHashMap.java:358)
at org.apache.openjpa.lib.util.concurrent.ConcurrentHashMap.put(ConcurrentHashMap.java:343)
at org.apache.openjpa.util.CacheMap.put(CacheMap.java:174)
at org.apache.openjpa.util.CacheMap.put(CacheMap.java:395)
at java.util.Collections$SynchronizedMap.put(Collections.java:2041)
at org.apache.openjpa.kernel.QueryImpl.compilationFromCache(QueryImpl.java:662)
at org.apache.openjpa.kernel.QueryImpl.compileForCompilation(QueryImpl.java:620)
at org.apache.openjpa.kernel.QueryImpl.compileForExecutor(QueryImpl.java:682)
at org.apache.openjpa.kernel.QueryImpl.compile(QueryImpl.java:589)
at org.apache.openjpa.persistence.EntityManagerImpl.createQuery(EntityManagerImpl.java:997)
at org.apache.openjpa.persistence.EntityManagerImpl.createQuery(EntityManagerImpl.java:979)
at org.apache.openjpa.persistence.EntityManagerImpl.createQuery(EntityManagerImpl.java:102)
at com.sun.enterprise.container.common.impl.EntityManagerWrapper.createQuery(EntityManagerWrapper.java:436)
at ch.astorm.ejb.facade.EntryPointBean.privateInsert(EntryPointBean.java:51)
at ch.astorm.ejb.facade.EntryPointBean.insertWithTransaction(EntryPointBean.java:32)

Analyse

Lorsqu'on remonte à la source de l'erreur, Glassfish émet une grosse alerte dans les logs:

WARNING: LDR5207: ASURLClassLoader EarLibClassLoader :
doneCalled = true
doneSnapshot = ASURLClassLoader.done() called ON EarLibClassLoader :
urlSet = [...]
doneCalled = false
 Parent -> org.glassfish.internal.api.DelegatingClassLoader@6dd938f0
 AT Wed Nov 27 21:09:54 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)
at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:240)
at org.glassfish.deployment.admin.DeployCommand.execute(DeployCommand.java:389)
at com.sun.enterprise.v3.admin.CommandRunnerImpl$1.execute(CommandRunnerImpl.java:348)
at com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:363)
at com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:1085)
at com.sun.enterprise.v3.admin.CommandRunnerImpl.access$1200(CommandRunnerImpl.java:95)
at com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1291)
at com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1259)
at com.sun.enterprise.v3.admin.AdminAdapter.doCommand(AdminAdapter.java:461)
at com.sun.enterprise.v3.admin.AdminAdapter.service(AdminAdapter.java:212)
at com.sun.grizzly.tcp.http11.GrizzlyAdapter.service(GrizzlyAdapter.java:179)
at com.sun.enterprise.v3.server.HK2Dispatcher.dispath(HK2Dispatcher.java:117)
at com.sun.enterprise.v3.services.impl.ContainerMapper$Hk2DispatcherCallable.call(ContainerMapper.java:354)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:195)
at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:860)
at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:757)
at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1056)
at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:229)
at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
at java.lang.Thread.run(Thread.java:744)
 Parent -> org.glassfish.internal.api.DelegatingClassLoader@6dd938f0
 was requested to find class org.apache.openjpa.lib.util.concurrent.ConcurrentReferenceHashMap$SoftEntry after done was invoked from the following stack trace 

Visiblement cette obscure stacktrace semble indiquer que le ClassLoader en question est considéré comme détruit mais qu'il y a tout de même du code qui nécessite d'aller recherche une classe lui appartenant. Si on regarde le code source de la classe ASURLClassLoader, on voit bien que si la méthode done() a été appelée, alors un ClassNotFoundException est lancé (ligne 708).

En fait le ClassLoader est géré par le container (en l'occurrence Glassfish) et visiblement OpenJPA s'initialise au mauvais moment puisqu'une de ses classes se retrouve enregistrée dans le mauvais ClassLoader. Ceci étant une configuration de base, je me suis permis d'ouvrir un bug majeur sur leur JIRA.

Résolution

J'ai fais plusieurs tests et le plus simple est clairement d'utiliser les bonnes pratiques habituelles et d'utiliser des requêtes paramétrées:

entityManager.createQuery("SELECT p FROM Person p WHERE p.id=?1").setParameter(1, pid).getSingleResult();

Bien évidemment, dans mon cas il n'est pas possible de repasser sur toutes les requêtes pour les paramétrer, notamment car certaines sont générées dynamiquement. Il y a d'ailleurs quelques contraintes avec les bases de données Oracle qui ne supportent pas des prédicats IN avec plus de 1000 éléments. Bref, il me fallait une autre solution...

En fouillant le code source d'OpenJPA, je me suis rendu compte que la classe non trouvée est liée à la gestion du cache des requêtes compilées, ce qui explique pourquoi une requête paramétrée fonctionne et une requête dynamique pas. Avec une requête paramétrée telle que montrée ci-dessus, cette dernière ne sera compilée qu'une seule fois et appelée ensuite à de multiples reprises. Dans le cas d'origine, avec une requête dynamique, OpenJPA va à chaque fois considérer que c'est une nouvelle requête, la recompiler et la stocker dans son cache (raison de plus pour utiliser des paramètres me direz-vous).

Finalement, j'ai réussi à trouver cette propriété d'OpenJPA qui permet de gérer le cache de la compilation. J'ai donc essayé avec les deux paramètres false et all. La bonne surprise c'est que les deux valeurs résolvent le problème ! Maintenant reste à choisir entre les performances amoindries résultantes du false car cela désactive complètement le cache et la mémoire nécessaire (potentiellement énorme) pour le all...

J'ai mis un petit projet en annexe pour reproduire le problème facilement. Il suffit de lancer le script leak-insert.sh lorsque le projet est déployé dans NetBeans.