[TAPESTRY-1993] tapestry-hibernate tests work slow, generate large amounts of warnings - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Closed
Priority: Major
Resolution: Cannot Reproduce
Affects Version/s: 5.0.7
Fix Version/s: None
Component/s: tapestry-hibernate
Labels:
None

Description

Very concerned that the warnings indicate failures and the tests are passing incorrectly.

[WARN] ThreadPoolAsynchronousRunner com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@97c401 – APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
[WARN] ThreadPoolAsynchronousRunner com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@97c401 – APPARENT DEADLOCK!!! Complete Status:
Managed Threads: 3
Active Threads: 3
Active Tasks:
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@b7ff0e (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0)
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@ca01f0 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1)
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@4563aa (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2)
Pending Tasks:
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@926c19
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@f6fb59
Pool thread stack traces:
Threadcom.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,main
java.lang.Thread.sleep(Native Method)
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1805)
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
Threadcom.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,main
java.lang.Thread.sleep(Native Method)
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1805)
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
Threadcom.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2,5,main
java.lang.Thread.sleep(Native Method)
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1805)
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)

[WARN] BasicResourcePool com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@b7ff0e – Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
java.sql.SQLException: The database is already in use by another process: org.hsqldb.persist.NIOLockFile@1aaa8f9c[file =/Users/Howard/work/tapestry5/target/unit-testdb.lck, exists=false, locked=false, valid=false, fl =null]: java.io.FileNotFoundException: /Users/Howard/work/tapestry5/target/unit-testdb.lck (No such file or directory)
at org.hsqldb.jdbc.Util.sqlException(Unknown Source)
at org.hsqldb.jdbc.jdbcConnection.<init>(Unknown Source)
at org.hsqldb.jdbcDriver.getConnection(Unknown Source)
at org.hsqldb.jdbcDriver.connect(Unknown Source)
at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:135)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137)
at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)
at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
[WARN] BasicResourcePool com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@4563aa – Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
java.sql.SQLException: The database is already in use by another process: org.hsqldb.persist.NIOLockFile@1aaa8f9c[file =/Users/Howard/work/tapestry5/target/unit-testdb.lck, exists=false, locked=false, valid=false, fl =null]: java.io.FileNotFoundException: /Users/Howard/work/tapestry5/target/unit-testdb.lck (No such file or directory)
at org.hsqldb.jdbc.Util.sqlException(Unknown Source)
at org.hsqldb.jdbc.jdbcConnection.<init>(Unknown Source)
at org.hsqldb.jdbcDriver.getConnection(Unknown Source)
at org.hsqldb.jdbcDriver.connect(Unknown Source)
at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:135)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137)
at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)
at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
[WARN] BasicResourcePool com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@ca01f0 – Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
java.sql.SQLException: The database is already in use by another process: org.hsqldb.persist.NIOLockFile@1aaa8f9c[file =/Users/Howard/work/tapestry5/target/unit-testdb.lck, exists=false, locked=false, valid=false, fl =null]: java.io.FileNotFoundException: /Users/Howard/work/tapestry5/target/unit-testdb.lck (No such file or directory)
at org.hsqldb.jdbc.Util.sqlException(Unknown Source)
at org.hsqldb.jdbc.jdbcConnection.<init>(Unknown Source)
at org.hsqldb.jdbcDriver.getConnection(Unknown Source)
at org.hsqldb.jdbcDriver.connect(Unknown Source)
at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:135)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)
at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137)
at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)
at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
[WARN] SettingsFactory Could not obtain connection 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.connection.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:56)
at org.hibernate.cfg.SettingsFactory.buildSettings(SettingsFactory.java:84)
at org.hibernate.cfg.Configuration.buildSettings(Configuration.java:2009)
at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1292)
at org.apache.tapestry.internal.hibernate.HibernateSessionSourceImpl.<init>(HibernateSessionSourceImpl.java:43)
at org.apache.tapestry.internal.hibernate.HibernateSessionSourceImplTest.get_configuration(HibernateSessionSourceImplTest.java:77)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.testng.internal.MethodHelper.invokeMethod(MethodHelper.java:580)
at org.testng.internal.Invoker.invokeMethod(Invoker.java:478)
at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:607)
at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:874)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109)
at org.testng.TestRunner.runWorkers(TestRunner.java:689)
at org.testng.TestRunner.privateRun(TestRunner.java:566)
at org.testng.TestRunner.run(TestRunner.java:466)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:301)
at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:296)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:276)
at org.testng.SuiteRunner.run(SuiteRunner.java:191)
at org.testng.TestNG.createAndRunSuiteRunners(TestNG.java:808)
at org.testng.TestNG.runSuitesLocally(TestNG.java:776)
at org.testng.TestNG.run(TestNG.java:701)
at org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:78)
at org.apache.maven.surefire.testng.TestNGXmlTestSuite.execute(TestNGXmlTestSuite.java:92)
at org.apache.maven.surefire.Surefire.run(Surefire.java:177)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:334)
at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:977)
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)
... 36 more
[INFO] HibernateSessionSourceTest Hibernate startup: 138 ms to configure, 30,035 ms overall.
[INFO] HibernateSessionSourceTest Configured Hibernate entities:
[WARN] AnnotationBinder Package not found or wo package-info.java: org.example.myapp.entities
[WARN] AnnotationBinder Package not found or wo package-info.java: org.example.app0.entities

Attachments

Activity

People

Assignee:: Howard Lewis Ship

Reporter:: Howard Lewis Ship

Votes:: 0 Vote for this issue

Watchers:: 0 Start watching this issue

Dates

Created:: 20/Dec/07 19:15

Updated:: 08/Feb/08 00:09

Resolved:: 08/Feb/08 00:09