I have a very simple application template which includes an embedded apache derby database through hibernate.
I have the following configuration:
<property name="hibernate.dialect"> org.hibernate.dialect.DerbyTenSevenDialect</property>
<property name="hibernate.connection.driver_class"> org.apache.derby.jdbc.EmbeddedDriver </property>
<property name="hibernate.connection.username"></property>
<property name="hibernate.connection.password"></property>
<property name="current_session_context_class">thread</property>
<property name="connection.pool_size">10</property>
<property name="connection.provider_class">org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider</property>
<property name="hibernate.c3p0.acquire_increment">1</property>
<property name="hibernate.c3p0.min_size">5</property>
<property name="hibernate.c3p0.max_size">20</property>
<property name="hibernate.c3p0.timeout">300</property>
<property name="hibernate.c3p0.idle_test_period">3000</property>
<property name="hibernate.c3p0.max_statements">50</property>
<property name="hibernate.c3p0.testConnectionOnCheckout">true</property>
<property name="hibernate.hbm2ddl.auto">update</property>
<property name="cache.use_second_level_cache">false</property>
<property name="cache.use_query_cache">false</property>
<property name="cache.provider_class">org.hibernate.cache.NoCacheProvider</property>
<property name="hibernate.show_sql">false</property>
<property name="hibernate.format_sql">false</property>
and a the init method for the SessionFactory is:
public static void init(String hibernateConfigurationResource,String connectionUrl) {
try {
configuration = new Configuration();
configuration.configure(hibernateConfigurationResource);
if (connectionUrl == null || connectionUrl.length() == 0) {
connectionUrl = "myDb";
} else {
connectionUrl += File.separator + "myDb";
}
File f = new File(connectionUrl);
if (logger.isDebugEnabled()) {
logger.debug("Using db path: " + f.getAbsolutePath());
}
if (!f.exists()) {
if (logger.isDebugEnabled()) {
logger.debug("Database does not exist: creating");
}
connectionUrl += ";create=true";
}
configuration
.setProperty("hibernate.connection.url", "jdbc:derby:"
+ connectionUrl);
serviceRegistry =
new ServiceRegistryBuilder().applySettings(configuration.getProperties()).buildServiceRegistry();
sessionFactory = configuration.buildSessionFactory(serviceRegistry);
} catch (Throwable ex) {
throw new ExceptionInInitializerError(ex);
}
}
and at the destroy phase, this method is called:
public static void destroy() throws SQLException {
String connectionUrl = configuration
.getProperty("hibernate.connection.url").replace(";create=true", "");
try {
if (logger.isDebugEnabled()) {
logger.debug("Shutting down database: " + connectionUrl);
}
DriverManager.getConnection(connectionUrl + ";shutdown=true");
} catch (SQLNonTransientConnectionException e) {
if (logger.isDebugEnabled()) {
logger.debug(e.getMessage());
}
String message = e.getMessage();
if (!(message.startsWith("Database") && message
.endsWith("shutdown."))) {
throw e;
}
}
try {
Session s = sessionFactory.getCurrentSession();
if (s.isDirty()) {
s.flush();
}
s.disconnect();
s.close();
sessionFactory.close();
} catch (Exception e) {
logger.error(e);
}
Enumeration<Driver> drivers = DriverManager.getDrivers();
while (drivers.hasMoreElements()) {
Driver driver = drivers.nextElement();
try {
logger.info("Deregistering jdbc driver: " + driver);
DriverManager.deregisterDriver(driver);
} catch (SQLException e) {
logger.warn("Error deregistering driver " + driver, e);
}
}
}
I noticed that the application is running fine but as soon as I stop the tomcat, I see the following messages:
INFO: Stopping service Catalina
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/myWebApp-webapp] appears to have started a thread named [Timer-1] but has failed to stop it. This is very likely to create a memory leak.
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/myWebApp-webapp] appears to have started a thread named [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0] but has failed to stop it. This is very likely to create a memory leak.
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/myWebApp-webapp] appears to have started a thread named [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] but has failed to stop it. This is very likely to create a memory leak.
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/myWebApp-webapp] appears to have started a thread named [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2] but has failed to stop it. This is very likely to create a memory leak.
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [/myWebApp-webapp] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@106f4e54]) and a value of type [org.apache.derby.iapi.services.context.ContextManager] (value [org.apache.derby.iapi.services.context.ContextManager@587cc9a3]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [/myWebApp-webapp] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@106f4e54]) and a value of type [org.apache.derby.iapi.services.context.ContextManager] (value [org.apache.derby.iapi.services.context.ContextManager@2e704a6]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [/myWebApp-webapp] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@106f4e54]) and a value of type [org.apache.derby.iapi.services.context.ContextManager] (value [org.apache.derby.iapi.services.context.ContextManager@36bc4735]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
apr 17, 2013 4:34:36 PM org.apache.coyote.AbstractProtocolHandler stop
INFO: Stopping ProtocolHandler ["http-bio-8080"]
apr 17, 2013 4:34:36 PM org.apache.coyote.AbstractProtocolHandler stop
INFO: Stopping ProtocolHandler ["ajp-bio-8009"]
I am pretty sure that the problem is at the connection pooling level with Hibernate not being able to shut down the c3p0 connection provider properly. I tried also with mysql and the issue is still there.
I am also aware of the tomcat protection against memory leaks (that is actually producing that messages) and I am running Tomcat 7.0.39.
Moreover I don't want to move the connection pool outside the application (delegating the container).
How can I tell hibernate to shutdown everything properly and avoid those messages? What am I missing?
Thank you in advance!
EDIT:
The log on the shutdown just show:
2013-04-18 10:27:13,537 DEBUG [Thread-13] HibernateUtil - Shutting down database: jdbc:derby:myDb
2013-04-18 10:27:13,555 DEBUG [Thread-13] HibernateUtil - Database 'myDb' shutdown.
2013-04-18 10:27:13,656 DEBUG [Thread-13] SessionImpl - Disconnecting session
2013-04-18 10:27:13,656 DEBUG [Thread-13] LogicalConnectionImpl - Releasing JDBC connection
2013-04-18 10:27:13,658 DEBUG [Thread-13] SessionFactoryImpl - HHH000031: Closing
2013-04-18 10:27:13,659 INFO [Thread-13] HibernateUtil - Deregistering jdbc driver: sun.jdbc.odbc.JdbcOdbcDriver@35849932
2013-04-18 10:27:13,659 INFO [Thread-13] HibernateUtil - Deregistering jdbc driver: org.apache.derby.jdbc.AutoloadedDriver40@7d7ff794
On the startup I have only the following line for the class AbstractPoolBackedDataSource:
2013-04-18 10:25:38,808 INFO [Thread-2] AbstractPoolBackedDataSource - Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@28fe617e [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@8c36e25a [ acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 2s05jr8u7u65au1gs0zth|25e62c36, idleConnectionTestPeriod -> 3000, initialPoolSize -> 3, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 300, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 20, maxStatements -> 50, maxStatementsPerConnection -> 0, minPoolSize -> 5, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@423e8f48 [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> 2s05jr8u7u65au1gs0zth|363bec9c, jdbcUrl -> jdbc:derby:myDb, properties -> {user=******, password=******} ], preferredTestQuery -> null, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> true, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> 2s05jr8u7u65au1gs0zth|43ba9cea, numHelperThreads -> 3 ]
See Question&Answers more detail:
os