Thanks Steve, I wasn't sure if I had found a problem. Still, it looks like the Hibernate Search tests are not benefiting from auto-commit, or I wouldn't have this problem right? Our testing configuration properties have been the same for years and I'm just re-enabling tests which haven't been run for a while, so I suspect something changed in ORM.
I think I'd expect Hibernate ORM to automatically enable auto-commit on operations not running within a transaction, to make sure all locks are released when the Session is closed. Thanks, Sanne On 17 July 2015 at 00:14, Steve Ebersole <st...@hibernate.org> wrote: > For what it is worth, I am running into the same problems on MySQL for the > ORM tests in terms of blocks on dropping tables. PGSQL at least finishes, > although I run into 55 errors which I still need to triage. > > On Thu, Jul 16, 2015 at 5:59 PM Steve Ebersole <st...@hibernate.org> wrote: >> >> There is really nothing to improve. What would you suggest as an >> improvement? I mean from a ORM perspective, we have an ato-commit >> Connection (presumably) and run a query. How on earth would we know to >> expect that the database is holding locks for that? >> >> As far as "requiring transactions" I have tried to fly that plane multiple >> times in the past. I think it is absolutely ridiculous to allow these >> auto-commit use cases. In fact I personally wanted to take it to the more >> extreme case of always using JTA and simply mimicking "single resource JTA >> transactions" internally in the "JDBC transaction" case. Gavin and I both >> did in fact. But we got a lot of push back. >> >> So I am not sure exactly what the improvement here might be. What is it >> you were thinking specifically? >> >> On Thu, Jul 16, 2015 at 5:36 PM Sanne Grinovero <sa...@hibernate.org> >> wrote: >>> >>> I finally got to re-enable MariaDB and PostgreSQL based tests for >>> Hibernate Search - which has been running on H2 only for some months - >>> and had to debug a case of a single test hanging for a long time. >>> >>> Essentially it would block - for hours - on the SessionFactory#close() >>> method, attempting to drop the database schema with the following >>> statement: >>> > alter table AncientBook_alternativeTitles drop constraint >>> FKn8hhkmhof1mdgc4oi77ccq989 >>> >>> Dumping threads I would get a very similar stack trace on both >>> databases; initially I thought someone had copy/pasted a socket >>> handling bug from one JDBC driver to the other ;-) >>> >>> The PostgreSQL testsuite hanging: >>> >>> "main" prio=10 tid=0x00007f0f40009000 nid=0x5f7c runnable >>> [0x00007f0f48956000] >>> java.lang.Thread.State: RUNNABLE >>> at java.net.SocketInputStream.socketRead0(Native Method) >>> at java.net.SocketInputStream.read(SocketInputStream.java:152) >>> at java.net.SocketInputStream.read(SocketInputStream.java:122) >>> at >>> org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:145) >>> at >>> org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:114) >>> at >>> org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73) >>> at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:274) >>> at >>> org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1660) >>> at >>> org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257) >>> - locked <0x00000007c11e3860> (a >>> org.postgresql.core.v3.QueryExecutorImpl) >>> at >>> org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:500) >>> at >>> org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:374) >>> at >>> org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:302) >>> at >>> org.hibernate.tool.hbm2ddl.DatabaseExporter.export(DatabaseExporter.java:47) >>> at org.hibernate.tool.hbm2ddl.SchemaExport.perform(SchemaExport.java:476) >>> at org.hibernate.tool.hbm2ddl.SchemaExport.execute(SchemaExport.java:430) >>> at org.hibernate.tool.hbm2ddl.SchemaExport.drop(SchemaExport.java:375) >>> at org.hibernate.tool.hbm2ddl.SchemaExport.drop(SchemaExport.java:371) >>> at >>> org.hibernate.internal.SessionFactoryImpl.close(SessionFactoryImpl.java:1069) >>> at >>> org.hibernate.search.test.util.FullTextSessionBuilder.close(FullTextSessionBuilder.java:149) >>> at >>> org.hibernate.search.test.util.FullTextSessionBuilder$1.evaluate(FullTextSessionBuilder.java:248) >>> at org.junit.rules.RunRules.evaluate(RunRules.java:20) >>> at org.junit.runners.ParentRunner.run(ParentRunner.java:309) >>> at >>> org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264) >>> at >>> org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153) >>> at >>> org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124) >>> at >>> org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) >>> at >>> org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) >>> at >>> org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) >>> >>> The MariaDB testsuite hanging: >>> >>> "main" prio=10 tid=0x00007f8ca0009000 nid=0x4043 runnable >>> [0x00007f8ca5f5c000] >>> java.lang.Thread.State: RUNNABLE >>> at java.net.SocketInputStream.socketRead0(Native Method) >>> at java.net.SocketInputStream.read(SocketInputStream.java:152) >>> at java.net.SocketInputStream.read(SocketInputStream.java:122) >>> at >>> com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:114) >>> at >>> com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:161) >>> at >>> com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189) >>> - locked <0x00000007c0baa518> (a >>> com.mysql.jdbc.util.ReadAheadInputStream) >>> at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2499) >>> at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2952) >>> at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2941) >>> at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3489) >>> at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1959) >>> at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2113) >>> at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2562) >>> - locked <0x00000007c0baa850> (a java.lang.Object) >>> at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1664) >>> - locked <0x00000007c0baa850> (a java.lang.Object) >>> at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1583) >>> at >>> org.hibernate.tool.hbm2ddl.DatabaseExporter.export(DatabaseExporter.java:47) >>> at org.hibernate.tool.hbm2ddl.SchemaExport.perform(SchemaExport.java:476) >>> at org.hibernate.tool.hbm2ddl.SchemaExport.execute(SchemaExport.java:430) >>> at org.hibernate.tool.hbm2ddl.SchemaExport.drop(SchemaExport.java:375) >>> at org.hibernate.tool.hbm2ddl.SchemaExport.drop(SchemaExport.java:371) >>> at >>> org.hibernate.internal.SessionFactoryImpl.close(SessionFactoryImpl.java:1069) >>> at >>> org.hibernate.search.test.util.FullTextSessionBuilder.close(FullTextSessionBuilder.java:149) >>> at >>> org.hibernate.search.test.util.FullTextSessionBuilder$1.evaluate(FullTextSessionBuilder.java:248) >>> at org.junit.rules.RunRules.evaluate(RunRules.java:20) >>> at org.junit.runners.ParentRunner.run(ParentRunner.java:309) >>> at >>> org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264) >>> at >>> org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153) >>> at >>> org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124) >>> at >>> org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) >>> at >>> org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) >>> at >>> org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) >>> >>> On Gail's suggestion I went looking for database level locks; I hadn't >>> thought of that as I assumed it would have timed out more aggressively >>> rather than have me wait for hours. >>> It turns out she was right and the reason for blocking was a simple >>> "count *" query being run as a post-test assertion, which we had >>> forgotten to wrap in an "open transaction & commit" statements pair. >>> The test assertion would be successful, but apparently it would hold >>> on the table lock beyond closing the Session and, then fail to drop >>> the database at the teardown of the test. >>> >>> I'm wondering if this is expected, or if there's something in the new >>> transaction handling code which could be improved? It took me several >>> hours to figure this out; maybe I'm just not using ORM as frequently >>> as once :) >>> If it's this critical to have the transaction, maybe it should be >>> mandatory? >>> >>> And as a memo for next time, this is the query to figure out details >>> about locks on our testing db: >>> > SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid >>> = psa.pid where datname = 'testingdb'; >>> >>> Thanks, >>> Sanne >>> _______________________________________________ >>> hibernate-dev mailing list >>> hibernate-dev@lists.jboss.org >>> https://lists.jboss.org/mailman/listinfo/hibernate-dev _______________________________________________ hibernate-dev mailing list hibernate-dev@lists.jboss.org https://lists.jboss.org/mailman/listinfo/hibernate-dev
