ehcache CacheManager clash on jetty webapp redeploy

neek · **Joined:** Wed Sep 30, 2009 5:29 am **Posts:** 29

Environment: hibernate core 4.1.4 - hibernate search 4.1.1 - jetty 7.6.4

Thought about posting this on the ehcache forum, but I suspect it's more relevant to Hibernate Search configuration. Would welcome any pointers. I believe this was not a problem with Hibernate 3.6.5 and Hibernate Search 3.4.0 .. it's only since moving up to the 4.x releases that I've had this trouble.

I have a relatively simple web app, with a hibernate.cfg.xml that specifies that ehCache should be used.

Code:

      <property name="hibernate.cache.region.factory_class">org.hibernate.cache.ehcache.EhCacheRegionFactory</property>
      <property name="net.sf.ehcache.configurationResourceName">/ehcache.xml</property>
      <property name="hibernate.cache.use_second_level_cache">true</property>
      <property name="hibernate.cache.use_query_cache">true</property>

I package this into a .war and deploy to Jetty. This causes ehcache to load up, and initialize from ehcache.xml. This goes fine first time around.

When I redeploy the .war file and touch the contexts/MyWebApp.xml file to cause Jetty to shut down, redeploy, and start up my web app, I'm getting this exception:

Code:

Jul 10, 2012 6:17:31 AM org.eclipse.jetty.server.handler.ContextHandler$Context log
WARNING: unavailable
org.hibernate.cache.CacheException: net.sf.ehcache.CacheException: Another CacheManager with same name 'myappcache' already exists in the same VM. Please provide unique names for each CacheManager in the config or do one of following:
1. Use one of the CacheManager.create() static factory methods to reuse same CacheManager with same name or create one if necessary
2. Shutdown the earlier cacheManager before creating new one with same name.
The source of the existing CacheManager is: URLConfigurationSource [url=file:/tmp/jetty-0.0.0.0-8080-MyWebApp.war-_myapp-any-/webapp/WEB-INF/classes/ehcache.xml]
        at org.hibernate.cache.ehcache.EhCacheRegionFactory.start(EhCacheRegionFactory.java:110)
        at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:283)
        at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1744)
        at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1782)
        at ltd.myapp.db.core.HibernateUtil.initSessionFactory(HibernateUtil.java:31)
        at ltd.myapp.db.core.HibernateUtil.getSession(HibernateUtil.java:86)
        at ltd.myapp.servlets.MonitoringServlet.init(MonitoringServlet.java:136)
        at org.eclipse.jetty.servlet.ServletHolder.initServlet(ServletHolder.java:463)
        at org.eclipse.jetty.servlet.ServletHolder.doStart(ServletHolder.java:283)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:59)
        at org.eclipse.jetty.servlet.ServletHandler.initialize(ServletHandler.java:771)
        at org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:249)
        at org.eclipse.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1235)
        at org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:676)
        at org.eclipse.jetty.webapp.WebAppContext.doStart(WebAppContext.java:468)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:59)
        at org.eclipse.jetty.deploy.bindings.StandardStarter.processBinding(StandardStarter.java:36)
        at org.eclipse.jetty.deploy.AppLifeCycle.runBindings(AppLifeCycle.java:183)
        at org.eclipse.jetty.deploy.DeploymentManager.requestAppGoal(DeploymentManager.java:491)
        at org.eclipse.jetty.deploy.DeploymentManager.addApp(DeploymentManager.java:138)
        at org.eclipse.jetty.deploy.providers.ScanningAppProvider.fileChanged(ScanningAppProvider.java:160)
        at org.eclipse.jetty.deploy.providers.ScanningAppProvider$1.fileChanged(ScanningAppProvider.java:58)
        at org.eclipse.jetty.util.Scanner.reportChange(Scanner.java:658)
        at org.eclipse.jetty.util.Scanner.reportDifferences(Scanner.java:538)
        at org.eclipse.jetty.util.Scanner.scan(Scanner.java:398)
        at org.eclipse.jetty.util.Scanner$1.run(Scanner.java:348)
        at java.util.TimerThread.mainLoop(Timer.java:555)
        at java.util.TimerThread.run(Timer.java:505)
Caused by: net.sf.ehcache.CacheException: Another CacheManager with same name 'myappcache' already exists in the same VM. Please provide unique names for each CacheManager in the config or do one of following:
1. Use one of the CacheManager.create() static factory methods to reuse same CacheManager with same name or create one if necessary
2. Shutdown the earlier cacheManager before creating new one with same name.
The source of the existing CacheManager is: URLConfigurationSource [url=file:/tmp/jetty-0.0.0.0-8080-MyWebApp.war-_myappa-any-/webapp/WEB-INF/classes/ehcache.xml]
        at net.sf.ehcache.CacheManager.assertNoCacheManagerExistsWithSameName(CacheManager.java:458)
        at net.sf.ehcache.CacheManager.init(CacheManager.java:355)
        at net.sf.ehcache.CacheManager.<init>(CacheManager.java:243)
        at org.hibernate.cache.ehcache.EhCacheRegionFactory.start(EhCacheRegionFactory.java:94)
        ... 27 more

The solutions offered in the message are to use one of the CacheManager.create() static factory methods, which isn't an option for me as I'm letting Hibernate Search initialise ehcache for me, or shutting down the earlier CacheManager before creating a new one, which I thought Hibernate Search would manage for me.

My MonitoringServlet simply gets a Hibernate session with which to init the app, which works fine the first time around. Something about the app shutdown when Jetty redeploys the app is not closing the ehcache manager properly.

To work around this, I have to stop Jetty completely and start it up again every time I redeploy the app.

My main question is: do we have to configure anything, e.g. in hibernate.cfg.xml, to tell the second level cache, or EhCacheRegionFactory, to shut down when a web app is shut down?

My ehcache.xml file is pretty simple, and names the cache, which is the name seen in the exception message above:

Code:

<?xml version="1.0" encoding="UTF-8"?>
<ehcache name="myappcache"
       xsi:noNamespaceSchemaLocation="ehcache.xsd"
       updateCheck="false" monitoring="autodetect"
       dynamicConfig="true"
       maxBytesLocalHeap="10m"
       maxBytesLocalDisk="1g"
       timeToIdleSeconds="3600">

I can see that when the context xml file is touched, the Jetty webapp shutdown procedure seems to proceed normally. My MonitoringServlet has a destroy() method where it shuts down various services, which log normally:

Code:

    Jul 10, 2012 6:17:23 AM ltd.myapp.servlets.MonitoringServlet destroy
    INFO: Stopping quartz.
    Jul 10, 2012 6:17:23 AM org.quartz.core.QuartzScheduler shutdown
    INFO: Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED shutting down.
    Jul 10, 2012 6:17:23 AM org.quartz.core.QuartzScheduler standby
    INFO: Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED paused.
    Jul 10, 2012 6:17:23 AM org.quartz.core.QuartzScheduler shutdown
    INFO: Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED shutdown complete.
    [cut some of my thread shutdown logging]
    Jul 10, 2012 6:17:23 AM ltd.myapp.servlets.MonitoringServlet destroy
    INFO: Stopping broker...
    Jul 10, 2012 6:17:23 AM org.apache.activemq.broker.BrokerService stop
    INFO: ActiveMQ Message Broker (ourbroker, ID:vps.ourcompany.co.uk-47730-1341897402533-0:1) is shutting down
    Jul 10, 2012 6:17:24 AM org.apache.activemq.broker.TransportConnector stop
    INFO: Connector tcp Stopped
    Jul 10, 2012 6:17:26 AM org.apache.activemq.broker.TransportConnector stop
    INFO: Connector stomp Stopped
    Jul 10, 2012 6:17:26 AM org.apache.activemq.broker.TransportConnector stop
    INFO: Connector vm://ourbroker Stopped
    Jul 10, 2012 6:17:26 AM org.apache.activemq.store.kahadb.plist.PListStore doStop
    INFO: PListStore:[/opt/jetty/jetty-distribution-7.6.4.v20120524/activemq-data/ourbroker/tmp_storage ] stopped
    Jul 10, 2012 6:17:26 AM org.apache.activemq.store.kahadb.KahaDBStore doStop
    INFO: Stopping async queue tasks
    Jul 10, 2012 6:17:26 AM org.apache.activemq.store.kahadb.KahaDBStore doStop
    INFO: Stopping async topic tasks
    Jul 10, 2012 6:17:26 AM org.apache.activemq.store.kahadb.KahaDBStore doStop
    INFO: Stopped KahaDB
    Jul 10, 2012 6:17:26 AM org.apache.activemq.broker.BrokerService stop
    INFO: ActiveMQ JMS Message Broker (ourbroker, ID:vps.ourcompany.co.uk-47730-1341897402533-0:1) stopped
    Jul 10, 2012 6:17:26 AM ltd.myapp.servlets.MonitoringServlet destroy
    FINE: Stop requested.  Waiting until stopped...
    Jul 10, 2012 6:17:26 AM ltd.myapp.servlets.MonitoringServlet destroy
    INFO: Stopped broker OK.
    Jul 10, 2012 6:17:26 AM org.eclipse.jetty.servlet.listener.ELContextCleaner contextDestroyed
    INFO: javax.el.BeanELResolver purged
    Jul 10, 2012 6:17:26 AM org.eclipse.jetty.server.handler.ContextHandler doStop
    INFO: stopped o.e.j.w.WebAppContext{/mywebapp,file:/tmp/jetty-0.0.0.0-8080-MyWebApp.war-_mywebapp-any-/webapp/},/opt/jetty/jetty-distribution-7.6.4.v20120524/webapps/MyWebApp.war
    Jul 10, 2012 6:17:26 AM org.eclipse.jetty.deploy.DeploymentManager removeApp
    INFO: Deployable removed: App[o.e.j.w.WebAppContext{/mywebapp,null},/opt/jetty/jetty-distribution-7.6.4.v20120524/webapps/MyWebApp.war,/opt/jetty/jetty-distribution-7.6.4.v20120524/contexts/MyWebApp.xml]
    Jul 10, 2012 6:17:26 AM org.eclipse.jetty.deploy.DeploymentManager addApp
    INFO: Deployable added: /opt/jetty/jetty-distribution-7.6.4.v20120524/contexts/MyWebApp.xml
    Jul 10, 2012 6:17:26 AM org.eclipse.jetty.webapp.WebInfConfiguration unpack
    INFO: Extract jar:file:/opt/jetty/jetty-distribution-7.6.4.v20120524/webapps/MyWebApp.war!/ to /tmp/jetty-0.0.0.0-8080-MyWebApp.war-_mywebapp-any-/webapp
    Jul 10, 2012 6:17:28 AM org.eclipse.jetty.plus.webapp.PlusConfiguration bindUserTransaction
    INFO: No Transaction manager found - if your webapp requires one, please configure one.
    Jul 10, 2012 6:17:30 AM org.eclipse.jetty.server.handler.ContextHandler startContext

Perhaps I could put something in that servlet destroy() handler that would cleanly shut down the ehcache manager, so it can start up cleanly again once the web app is initialised again?

Nick

sanne.grinovero · **Posted:** Tue Jul 10, 2012 3:11 pm

Hi,
are you stopping the Hibernate SessionFactory?

http://docs.jboss.org/hibernate/core/4.1/javadocs/org/hibernate/SessionFactory.html#close()

neek · **Joined:** Wed Sep 30, 2009 5:29 am **Posts:** 29

sanne.grinovero wrote:

are you stopping the Hibernate SessionFactory?

Thanks very much for the response.. you were bang on the money, I wasn't manually closing the SessionFactory. It has taken me a few days to get our production deployment cleared for re-release, but it's now redeploying flawlessly.

Oddly, this seems to have been redeploying fine with Hibernate 3.x for a couple of years without real trouble. Perhaps something else has shifted in the 4.x upgrade. No matter, everything seems good now.

Thanks
Nick

sanne.grinovero · **Posted:** Mon Jul 16, 2012 9:21 am

Quote:

Oddly, this seems to have been redeploying fine with Hibernate 3.x for a couple of years without real trouble.

Unfortunately that's quite common a problem, but it has always been incorrect.

The #close() method has been there since I remember, and should always have been invoked in "proper" usage, but most of the time (depending on configuration / registered listeners) it's actually a no-op so you wouldn't notice it: core ORM components don't need it.
It might however always have been leaking some subtle to notice resources.. so always good to make sure it's invoked.

In case of Hibernate Search the resources include background threads, so it's harder to not notice, as you experienced ;-)

qwertz12345 · **Joined:** Wed Sep 21, 2011 2:20 pm **Posts:** 16

neek wrote:

Oddly, this seems to have been redeploying fine with Hibernate 3.x for a couple of years without real trouble. Perhaps something else has shifted in the 4.x upgrade. No matter, everything seems good now.

you are probably using ehcache >= 2.5 now. I am sure, this has to do with ehcache version >= 2.5.

regards

sanne.grinovero · **Posted:** Tue Jul 17, 2012 6:08 am

qwertz12345 wrote:

neek wrote:

Oddly, this seems to have been redeploying fine with Hibernate 3.x for a couple of years without real trouble. Perhaps something else has shifted in the 4.x upgrade. No matter, everything seems good now.

you are probably using ehcache >= 2.5 now. I am sure, this has to do with ehcache version >= 2.5.

Hi, it seems neek said shutting down the SessionFactory properly solved his problem. What is the problem of EHCache >= 2.5 ? is it also requiring the same close method? I haven't been using that myself for a while now, so if you could elaborate that would be great.

qwertz12345 · **Joined:** Wed Sep 21, 2011 2:20 pm **Posts:** 16

sanne.grinovero wrote:

Hi, it seems neek said shutting down the SessionFactory properly solved his problem.

yes, he is now doing, what is suggested in the error message:

neek wrote:

2. Shutdown the earlier cacheManager before creating new one with same name.

that is the correct solution in his situation.

sanne.grinovero wrote:

What is the problem of EHCache >= 2.5 ? is it also requiring the same close method? I haven't been using that myself for a while now, so if you could elaborate that would be great.

the problem is, that without first shutting down the ehcache manager, it will try to create a new one with the same name as before. and this is forbiddin since version 2.5 -- at least in the same VM.

you can read this in the introduction to ehcache:
http://ehcache.org/documentation/get-st ... troduction

ehcache manager documentation wrote:

Versions of Ehcache before version 2.5 allowed any number of CacheManagers with the same name (same configuration resource) to exist in a JVM. Therefore, each time new CacheManager(...) was called, a new CacheManager was created without regard to existing CacheManagers. Calling CacheManager.create(...) returned the existing singleton CacheManager with the configured name (if it existed) or created the singleton based on the passed-in configuration.

Ehcache 2.5 and higher does not allow multiple CacheManagers with the same name to exist in the same JVM. CacheManager() constructors creating non-Singleton CacheManagers can violate this rule, causing a NullPointerException. If your code may create multiple CacheManagers of the same name in the same JVM, avoid this error by using the static CacheManager.create() methods, which always return the named (or default unnamed) CacheManager if it already exists in that JVM. If the named (or default unnamed) CacheManager does not exist, the CacheManager.create() methods create it.

regards

sanne.grinovero · **Posted:** Wed Jul 18, 2012 7:28 am

thanks qwertz12345,
that was useful for me too.