Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
Re: [jetty-users] Strange connection pool behavior in Jetty 7.5.4

Just a quick note to say that we've had good reports and experiences
with using BoneCP as the connection pooling impl:

http://jolbox.com/

There's an example of how to set it up on the wiki page:
http://wiki.eclipse.org/Jetty/Howto/Configure_JNDI_Datasource#BoneCP


Jan

On 25 June 2012 10:20, Nick Fenwick <neek@xxxxxxxxxxxxxxx> wrote:
> 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
> jetty-users@xxxxxxxxxxx
> https://dev.eclipse.org/mailman/listinfo/jetty-users
>



-- 
Jan Bartel <janb@xxxxxxxxxxx>
www.webtide.com – Developer advice, services and support
from the Jetty & CometD experts.


Back to the top