1

There are various similar questions on here, but none with answers that fix my problem.

I'm running a Java EE app (YAWL built from source), which uses Hibernate and c3p0 to connect to a MySQL DB. The app runs on a Tomcat user instance (created via tomcat6-instance-create). It works perfectly on an Ubuntu 10.04 environment, but gets com.mchange.v2.resourcepool.CannotAcquireResourceException errors when 'upgrading' to Ubuntu 12.04.

The changes in the environment that seem relevant are:

  • MySQL 5.1.66 --> 5.5.28
  • Tomcat 6.0.24 --> 6.0.35
  • tomcat6-instance-create now adds a symlink lib folder (so that Eclipse can create instances properly; see Debian bug #297675)

Java has not changed: it's OpenJDK 6b24 on both releases.

Because of the last change, I had to play with catalina.properties to have my own shared libraries folder separate from the lib symlink, but I recreated this exactly on 10.04 and it still all worked OK there.

Extracts from INFO level Hibernate log are below. (The INFO level means you can see all the properties being used on the (long!) third line.)

[INFO] 2012-12-19 14:53:15,302 org.hibernate.annotations.common.Version - HCANN000001: Hibernate Commons Annotations {4.0.1.Final}
[INFO] 2012-12-19 14:53:15,308 org.hibernate.Version - HHH000412: Hibernate Core {4.1.2.Final}
[INFO] 2012-12-19 14:53:15,311 org.hibernate.cfg.Environment - HHH000205: Loaded properties from resource hibernate.properties: {hibernate.connection.password=****, hibernate.c3p0.acquire_increment=1, hibernate.query.substitutions=true 1, false 0, yes 'Y', no 'N', hibernate.cache.region_prefix=hibernate.test, hibernate.cache.region.factory_class=org.hibernate.cache.ehcache.EhCacheRegionFactory, hibernate.c3p0.idle_test_period=3000, hibernate.cache.use_second_level_cache=true, hibernate.show_sql=false, hibernate.c3p0.max_statements=100, hibernate.jdbc.batch_size=0, hibernate.bytecode.use_reflection_optimizer=false, hibernate.c3p0.timeout=5000, hibernate.generate_statistics=true, hibernate.cache.use_query_cache=true, hibernate.max_fetch_depth=1, hibernate.jdbc.use_streams_for_binary=true, hibernate.c3p0.min_size=2, hibernate.connection.username=root, hibernate.connection.driver_class=com.mysql.jdbc.Driver, hibernate.current_session_context_class=thread, hibernate.c3p0.max_size=20, hibernate.connection.provider_class=org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider, hibernate.cache.use_structured_entries=true, hibernate.dialect=org.hibernate.dialect.MySQLDialect, hibernate.connection.url=jdbc:mysql:///yawl_r1872}
[INFO] 2012-12-19 14:53:15,311 org.hibernate.cfg.Environment - HHH000407: Using java.io streams to persist binary types
[INFO] 2012-12-19 14:53:15,311 org.hibernate.cfg.Environment - HHH000021: Bytecode provider name : javassist
[INFO] 2012-12-19 14:53:15,331 org.hibernate.cfg.Configuration - HHH000221: Reading mappings from resource: org/yawlfoundation/yawl/resourcing/resource/Participant.hbm.xml

[...]

[INFO] 2012-12-19 14:53:15,970 org.hibernate.service.jdbc.connections.internal.ConnectionProviderInitiator - HHH000130: Instantiating explicit connection provider: org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider
[INFO] 2012-12-19 14:53:15,982 org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider - HHH010002: C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql:///yawl_r1872
[INFO] 2012-12-19 14:53:15,982 org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider - HHH000046: Connection properties: {user=root, password=****}
[INFO] 2012-12-19 14:53:15,983 org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider - HHH000006: Autocommit mode: false
[WARN] 2012-12-19 14:53:45,331 org.hibernate.engine.jdbc.internal.JdbcServicesImpl - HHH000342: Could not obtain connection to query metadata : Connections could not be acquired from the underlying database!

[...]

[INFO] 2012-12-19 14:53:45,788 org.hibernate.tool.hbm2ddl.SchemaUpdate - HHH000102: Fetching database metadata
[INFO] 2012-12-19 14:53:45,788 org.hibernate.service.jdbc.connections.internal.ConnectionProviderInitiator - HHH000130: Instantiating explicit connection provider: org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider
[INFO] 2012-12-19 14:53:45,789 org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider - HHH010002: C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql:///yawl_r1872
[INFO] 2012-12-19 14:53:45,789 org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider - HHH000046: Connection properties: {user=root, password=****}
[INFO] 2012-12-19 14:53:45,789 org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider - HHH000006: Autocommit mode: false
[ERROR] 2012-12-19 14:54:15,053 org.hibernate.tool.hbm2ddl.SchemaUpdate - HHH000319: Could not get database metadata
java.sql.SQLException: Connections could not be acquired from the underlying database!
    at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:106)
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:529)
    at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
    at org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:84)
    at org.hibernate.tool.hbm2ddl.ManagedProviderConnectionHelper.prepare(ManagedProviderConnectionHelper.java:55)
    at org.hibernate.tool.hbm2ddl.SchemaUpdate.execute(SchemaUpdate.java:194)
    at org.hibernate.tool.hbm2ddl.SchemaUpdate.execute(SchemaUpdate.java:178)
    at org.yawlfoundation.yawl.resourcing.datastore.HibernateEngine.initialise(HibernateEngine.java:121)
    at org.yawlfoundation.yawl.resourcing.datastore.HibernateEngine.<init>(HibernateEngine.java:88)
    at org.yawlfoundation.yawl.resourcing.datastore.HibernateEngine.getInstance(HibernateEngine.java:96)
    at org.yawlfoundation.yawl.resourcing.datastore.persistence.Persister.<init>(Persister.java:54)
    at org.yawlfoundation.yawl.resourcing.datastore.persistence.Persister.getInstance(Persister.java:59)
    at org.yawlfoundation.yawl.resourcing.ResourceManager.setPersisting(ResourceManager.java:1794)
    at org.yawlfoundation.yawl.resourcing.rsInterface.ResourceGateway.init(ResourceGateway.java:83)
    at javax.servlet.GenericServlet.init(GenericServlet.java:212)
    at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1206)
    at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1026)
    at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4421)
    at org.apache.catalina.core.StandardContext.start(StandardContext.java:4734)
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:799)
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:779)
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:601)
    at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:943)
    at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:778)
    at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:504)
    at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1317)
    at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:324)
    at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:142)
    at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1065)
    at org.apache.catalina.core.StandardHost.start(StandardHost.java:840)
    at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1057)
    at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:463)
    at org.apache.catalina.core.StandardService.start(StandardService.java:525)
    at org.apache.catalina.core.StandardServer.start(StandardServer.java:754)
    at org.apache.catalina.startup.Catalina.start(Catalina.java:595)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
Caused by: com.mchange.v2.resourcepool.CannotAcquireResourceException: A ResourcePool could not acquire a resource from its primary factory or source.
    at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1319)
    at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)
    at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)
    ... 40 more

The Hibernate and c3p0 properties are as below:

hibernate.query.substitutions true 1, false 0, yes 'Y', no 'N'
hibernate.dialect org.hibernate.dialect.MySQLDialect
hibernate.connection.driver_class com.mysql.jdbc.Driver
hibernate.connection.url jdbc:mysql:///yawl_r1872
hibernate.connection.username root
hibernate.connection.password yawl
hibernate.c3p0.max_size 20
hibernate.c3p0.min_size 2
hibernate.c3p0.timeout 5000
hibernate.c3p0.max_statements 100
hibernate.c3p0.idle_test_period 3000
hibernate.c3p0.acquire_increment 1
hibernate.connection.provider_class org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider
hibernate.show_sql false
hibernate.current_session_context_class thread
hibernate.generate_statistics true
hibernate.jdbc.batch_size 0
hibernate.jdbc.use_streams_for_binary true
hibernate.max_fetch_depth 1
hibernate.cache.region_prefix hibernate.test
hibernate.cache.use_second_level_cache true
hibernate.cache.use_query_cache true
hibernate.cache.use_structured_entries true
hibernate.cache.region.factory_class org.hibernate.cache.ehcache.EhCacheRegionFactory

Since these properties are listed in the INFO comments, I assume that they are definitely being read and used properly. I can connect fine to the database using mysql yawl_r1872 -u root -p yawl, so the credentials are fine (and, remember, it works fine on Ubuntu 10.04).

Things I've tried that haven't worked:

  • using a non-shared-libs configuration (with libs per webapp)
  • using Hibernate dialects MySQL5Dialect and MySQL5InnoDBDialect
  • using connection URLs with the host and port explicitly given (e.g., //localhost:3306/yawl_r1872) and with DB names without underscores in
  • uncommenting max_connections = 100 in /etc/mysql/my.cnf. (I think it defaults to 100 anyway.)
  • upgrading the MySQL Connector/J library (from 5.1.13 to 5.1.22)
  • using a Tomcat 7.0.26 instance (via Ubuntu tomcat7-user package; this doesn't have the symbolic lib link fix in, interestingly)
  • using a MySQL v5.1.66 server via MySQL Sandbox (with the normal MySQL 5.5 instance down). I think I set this up right: added bind-address = 127.0.0.1 to its .cnf file, checked that it was listening correctly on 127.0.0.1:5166, and used connection URL jdbc:mysql://127.0.0.1:5166/yawl_r1872 with username root and password msandbox
  • checking that I could connect to MySQL forcing use of TCP via mysql yawl_r1872 --protocol=TCP -h 127.0.0.1 -u root -p. (Apparently, UNIX sockets are used by default, so previously I wasn't actually confirming that a JDBC-style TCP connection could be made.)
  • checking the JDBC connection from some minimal Java JDBC code (worked fine)

For completeness, below is my catalina.properties setup, using a shared folder inside the instance ($CATALINA.BASE):

package.access=sun.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper.,sun.beans. 
package.definition=sun.,java.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper.
common.loader=${catalina.base}/shared,${catalina.base}/shared/*.jar,${catalina.base}/lib,${catalina.base}/lib/*.jar,${catalina.home}/lib,${catalina.home}/lib/*.jar
server.loader=
shared.loader=
tomcat.util.buf.StringCache.byte.enabled=true

Any help much appreciated!

Stuart Rossiter
  • 2,432
  • 1
  • 17
  • 20
  • I also used MySQL Sandbox to run MySQL 5.5.28 and 5.1.66 on my working Ubuntu 10.04 environment. These both worked fine (and confirmed that I was setting it up properly), so it would seem to be something more fundamental to Ubuntu 12.04 (like firewall configuration, but there is no firewall installed). – Stuart Rossiter Dec 20 '12 at 14:25

1 Answers1

0

It turned out that it was Hibernate itself. The code was using v4.1.2 (which uses c3p0 v0.9.1). On upgrading to v4.1.9 (which still ships with c3p0 v0.9.1), it all magically fixed itself. I hadn't tried upgrading Hibernate and c3p0 previously because the same code worked perfectly on Ubuntu 10.04 and the test I did using MySQL Sandbox with MySQL v5.1 should have ruled out any DB functionality/API issues affecting the code.

I trawled through the Hibernate changelog for 4.1.2 to 4.1.9, but couldn't see anything which would seem relevant, so I still remain in the dark about what aspect of the Ubuntu 12.04 environment it had problems with compared to 10.04.

(It remained working when also upgrading to the latest c3p0 v0.9.2-pre8 release, and the MySQL Connector/J update for good measure.)

Stuart Rossiter
  • 2,432
  • 1
  • 17
  • 20