On 11/18/2011 04:19 AM, Daniel Murnane wrote:
The next message defines driverClass and jdbcUrl, then User is
defined, then password, then maxpoolsize, and finally minpoolsize.
Everything defined in a previous message stays defined, so the last
message has everything defined properly.
Any ideas why this is behaving strangely?
Did you find a solution for this old problem? I'm seeing something
similar with C3P0, except the properties appear in groups rather than
one by one.
Long story short, I've switched back to DBCP and given up on C3P0. I'm
not clear which is better to use, but at least DBCP works.
I'm deploying with an embedded 7.6.4 with a WEB-INF/jetty-env.xml like this:
<?xml version="1.0" encoding="ISO-8859-1"?>
<!DOCTYPE Configure PUBLIC "-//Mort Bay Consulting//DTD Configure//EN"
"http://www.eclipse.org/jetty/configure.dtd";>
<Configure id="wac" class="org.eclipse.jetty.webapp.WebAppContext">
<New id="my-pool" class="org.eclipse.jetty.plus.jndi.Resource">
<Arg><Ref id="wac" /></Arg>
<Arg>jdbc/my-pool</Arg>
<Arg>
<New class="com.mchange.v2.c3p0.ComboPooledDataSource">
<Set name="description">Foo Bar</Set>
<Set name="driverClass">org.gjt.mm.mysql.Driver</Set>
<Set name="jdbcUrl">jdbc:mysql://localhost/mydb</Set>
<Set name="user">myuser</Set>
<Set name="password">mypass<Set>
</New>
</Arg>
</New>
</Configure>
This is being run from an embedded Jetty Main, where I pull in the Plus
configuration classes by name in a webApp.setConfigurationClasses( .. )
call and point Jetty at the WEB-INF folder via
webApp.setBaseResource(..). I have seen this same configuration work
when compiled into a war and deployed as a traditional webapp and run
with "java -jar start.jar".
As you describe, the first time the pool tries to initialise, various
important properties are null:
=====
[java] INFO: jetty-7.6.4.v20120524
[java] 20120625.140729.734 INFO MLog - MLog clients using log4j
logging.
[java] 20120625.140729.783 INFO C3P0Registry - Initializing
c3p0-0.9.1 [built 16-January-2007 14:46:42; debug? true; trace: 10]
[java] 20120625.140729.816 DEBUG
DynamicPooledDataSourceManagerMBean - MBean:
com.mchange.v2.c3p0:type=PooledDataSource[z8kflt8o9k9z6e1gsygqc|6a4cae18] registered.
[java] 20120625.140729.822 WARN C3P0Config - named-config with
name 'false' does not exist. Using default-config.
[java] 20120625.140729.887 DEBUG BasicResourcePool - incremented
pending_acquires: 1
[java] 20120625.140729.887 DEBUG BasicResourcePool - incremented
pending_acquires: 2
[java] 20120625.140729.887 DEBUG BasicResourcePool - incremented
pending_acquires: 3
[java] 20120625.140729.887 DEBUG BasicResourcePool -
com.mchange.v2.resourcepool.BasicResourcePool@23aba7b0 config: [start ->
3; min -> 3; max -> 15; inc -> 3; num_acq_attempts -> 30;
acq_attempt_delay -> 1000; check_idle_resources_delay -> 0;
mox_resource_age -> 0; max_idle_time -> 0; excess_max_idle_time -> 0;
destroy_unreturned_resc_time -> 0; expiration_enforcement_delay -> 0;
break_on_acquisition_failure -> false; debug_store_checkout_exceptions
-> false]
[java] 20120625.140729.910 INFO AbstractPoolBackedDataSource -
Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [
acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay ->
1000, autoCommitOnClose -> false, automaticTestTable -> null,
breakAfterAcquireFailure -> false, checkoutTimeout -> 0,
connectionCustomizerClassName -> null, connectionTesterClassName ->
com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName ->
false, debugUnreturnedConnectionStackTraces -> false, description ->
null, driverClass -> null, factoryClassLocation -> null,
forceIgnoreUnresolvedTransactions -> false, identityToken ->
z8kflt8o9k9z6e1gsygqc|6a4cae18, idleConnectionTestPeriod -> 0,
initialPoolSize -> 3, jdbcUrl -> null, lastAcquisitionFailureDefaultUser
-> null, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0,
maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 15,
maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 3,
numHelperThreads -> 3, numThreadsAwaitingCheckoutDefaultUser -> 0,
preferredTestQuery -> null, properties -> {}, propertyCycle -> 0,
testConnectionOnCheckin -> false, testConnectionOnCheckout -> false,
unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies ->
false ]
[java] 20120625.140729.910 DEBUG BasicResourcePool - An exception
occurred while acquiring a poolable resource. Will retry.
[java] java.lang.NullPointerException
[java] at
sun.jdbc.odbc.JdbcOdbcDriver.getProtocol(JdbcOdbcDriver.java:524)
[java] at
sun.jdbc.odbc.JdbcOdbcDriver.knownURL(JdbcOdbcDriver.java:493)
[java] at
sun.jdbc.odbc.JdbcOdbcDriver.acceptsURL(JdbcOdbcDriver.java:307)
[java] at java.sql.DriverManager.getDriver(DriverManager.java:273)
=====
Because driverUrl is null, the attempt to call DriverManager.getDriver
ends up throwing a NullPointerException.
I don't see how the creation of the ComboPooledDataSource defined in
jetty-env.xml could have "half completed", to the point where something
is trying to instantiate a database connection via c3p0 yet the
configuration parameters haven't yet been applied to the c3p0 data
source. Surely the way Jetty sets it up from the XML configuration is
atomic, i.e. nothing can use the data source until the XML configuration
has finished configuring it?
There is nothing else in my project that refers to c3p0 except
jetty-env.xml. I have used a manual DBCP connection provider before
now, this is the first time I've tried to use JNDI and c3p0.
I have removed from hibernate.cfg.xml any database configuraiton such as
the c3p0 directives that might cause it to try to initialise c3p0 in any
way, so I don't think it's trying to create c3p0 objects in parallel, or
conflicting, with the JNDI configuration. I did try fetching the c3p0
source and debugging via NetBeans
Further down the log, I see another attempt to initialize c3p0. This
time, 'description', 'driverClass' and 'driverUrl' have been filled in
.. however, the username and password have not. Just below _that_,
there is yet another dump of the properties, with the username
apparently filled in ('*****') but no password ('using password: NO').
=====
[java] 20120625.140729.969 INFO AbstractPoolBackedDataSource -
Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [
acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay ->
1000, autoCommitOnClose -> false, automaticTestTable -> null,
breakAfterAcquireFailure -> false, checkoutTimeout -> 0,
connectionCustomizerClassName -> null, connectionTesterClassName ->
com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName ->
false, debugUnreturnedConnectionStackTraces -> false, description -> Foo
Bar, driverClass -> org.gjt.mm.mysql.Driver, factoryClassLocation ->
null, forceIgnoreUnresolvedTransactions -> false, identityToken ->
z8kflt8o9k9z6e1gsygqc|6a4cae18, idleConnectionTestPeriod -> 0,
initialPoolSize -> 3, jdbcUrl -> jdbc:mysql://localhost/mydb,
lastAcquisitionFailureDefaultUser -> null, maxAdministrativeTaskTime ->
0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections
-> 0, maxPoolSize -> 15, maxStatements -> 0, maxStatementsPerConnection
-> 0, minPoolSize -> 3, numHelperThreads -> 3,
numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> null,
properties -> {}, propertyCycle -> 0, testConnectionOnCheckin -> false,
testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0,
usesTraditionalReflectiveProxies -> false ]
[java] 20120625.140730.010 DEBUG BasicResourcePool - incremented
pending_acquires: 1
[java] 20120625.140730.010 DEBUG BasicResourcePool - incremented
pending_acquires: 2
[java] 20120625.140730.010 DEBUG BasicResourcePool - incremented
pending_acquires: 3
[java] 20120625.140730.010 DEBUG BasicResourcePool -
com.mchange.v2.resourcepool.BasicResourcePool@64c14e1c config: [start ->
3; min -> 3; max -> 15; inc -> 3; num_acq_attempts -> 30;
acq_attempt_delay -> 1000; check_idle_resources_delay -> 0;
mox_resource_age -> 0; max_idle_time -> 0; excess_max_idle_time -> 0;
destroy_unreturned_resc_time -> 0; expiration_enforcement_delay -> 0;
break_on_acquisition_failure -> false; debug_store_checkout_exceptions
-> false]
[java] 20120625.140730.011 INFO AbstractPoolBackedDataSource -
Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [
acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay ->
1000, autoCommitOnClose -> false, automaticTestTable -> null,
breakAfterAcquireFailure -> false, checkoutTimeout -> 0,
connectionCustomizerClassName -> null, connectionTesterClassName ->
com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName ->
false, debugUnreturnedConnectionStackTraces -> false, description -> Foo
Bar, driverClass -> org.gjt.mm.mysql.Driver, factoryClassLocation ->
null, forceIgnoreUnresolvedTransactions -> false, identityToken ->
z8kflt8o9k9z6e1gsygqc|6a4cae18, idleConnectionTestPeriod -> 0,
initialPoolSize -> 3, jdbcUrl -> jdbc:mysql://localhost/mydb,
lastAcquisitionFailureDefaultUser -> null, maxAdministrativeTaskTime ->
0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections
-> 0, maxPoolSize -> 15, maxStatements -> 0, maxStatementsPerConnection
-> 0, minPoolSize -> 3, numHelperThreads -> 3,
numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> null,
properties -> {user=******}, propertyCycle -> 0, testConnectionOnCheckin
-> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout
-> 0, usesTraditionalReflectiveProxies -> false ]
[java] Jun 25, 2012 2:07:30 PM
org.eclipse.jetty.plus.webapp.PlusConfiguration bindUserTransaction
[java] INFO: No Transaction manager found - if your webapp
requires one, please configure one.
[java] 20120625.140730.089 DEBUG BasicResourcePool - An exception
occurred while acquiring a poolable resource. Will retry.
[java] java.sql.SQLException: Access denied for user
'myuser'@'localhost' (using password: NO)
[java] at
com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1075)
[java] at
com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3562)
[java] at
com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3494)
[java] at
com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:920)
[java] at com.mysql.jdbc.MysqlIO.secureAuth411(MysqlIO.java:4000)
[java] at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1285)
[java] at
com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2186)
[java] at
com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:787)
[java] at
com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:49)
[java] at
sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[java] at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
[java] at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
[java] at
java.lang.reflect.Constructor.newInstance(Constructor.java:525)
[java] at com.mysql.jdbc.Util.handleNewInstance(Util.java:409)
[java] at
com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:357)
[java] at
com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:285)
[java] at
com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:135)
[java] at
com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
[java] at
com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)
[java] at
com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137)
[java] at
com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)
[java] at
com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
[java] at
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
[java] at
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
=====
All this is logged on startup, without the app ever becoming usable. I
can't tell from the stack trace what is initialising what, when. There
are servlets that initialise on startup and use the database but they
come in later, and I have mangled the JNDI name they would use via
hibernate.connection.datasource so they fail to resolve it. So, I'm
sure all this logging is produced during simple startup and
initialisation of the JNDI data source.
I've been banging away at this problem for hours.
I did see it work once, and thought the planets were in alignment and I
finally had the config right. Just after that it failed again and
hasn't worked since. It stinks of some kind of race condition, as if
the XML configuration performed by Jetty as it sets up the data source
is not atomic.
I then noticed that there is DBCP configuration given on the Jetty JNDI
page http://wiki.eclipse.org/Jetty/Howto/Configure_JNDI_Datasource#dbcp
which worked first time. I had previously given up on DBCP, because the
Connection Provider code given on the wiki
http://wiki.apache.org/commons/DBCP/Hibernate is not compatible with the
Hibernate 4 release, but employing DBCP via JNDI avoids the need for my
project to include the Provider code.
Nick
_______________________________________________
jetty-users mailing list
[email protected]
https://dev.eclipse.org/mailman/listinfo/jetty-users
