We're updating the issue view to help you get more done. 

SessionJdbcBatchTest hangs with DB2

Description

org.hibernate.test.jdbc.internal.SessionJdbcBatchTest hangs with DB2

Test log:

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 org.hibernate.test.jdbc.internal.SessionJdbcBatchTest STANDARD_OUT 08:02:00,535 INFO CustomRunner:116 - BeforeClass: org.hibernate.test.jdbc.internal.SessionJdbcBatchTest 08:02:00,541 WARN CachingRegionFactory:47 - org.hibernate.testing.cache.CachingRegionFactory should be only used for testing. 08:02:00,541 DEBUG RegionFactoryInitiator:49 - Cache region factory : org.hibernate.testing.cache.CachingRegionFactory 08:02:00,546 WARN pooling:73 - HHH10001002: Using Hibernate built-in connection pool (not for production use!) 08:02:00,546 INFO pooling:129 - HHH10001005: using driver [com.ibm.db2.jcc.DB2Driver] at URL [jdbc:db2://db2-111.rhev-ci-vms.eng.rdu2.redhat.com:50000/dballo] 08:02:00,546 INFO pooling:138 - HHH10001001: Connection properties: {user=dballo18, password=****} 08:02:00,546 INFO pooling:143 - HHH10001003: Autocommit mode: false 08:02:00,546 INFO DriverManagerConnectionProviderImpl:281 - HHH000115: Hibernate connection pool size: 5 (min=1) 08:02:00,744 INFO Dialect:157 - HHH000400: Using dialect: org.hibernate.dialect.DB297Dialect 08:02:00,762 INFO beans:73 - HHH10005002: No explicit CDI BeanManager reference was passed to Hibernate, but CDI is available on the Hibernate ClassLoader. 08:02:00,769 DEBUG SQL:94 - drop table Event Hibernate: drop table Event 08:02:00,770 INFO access:47 - HHH10001501: Connection obtained from JdbcConnectionAccess [org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@11589a55] for (non-JTA) DDL execution was not in auto-commit mode; the Connection 'local transaction' will be committed and the Connection will be set into auto-commit mode. 08:02:00,784 WARN ExceptionHandlerLoggedImpl:27 - GenerationTarget encountered exception accepting command : Error executing DDL " drop table Event" via JDBC Statement org.hibernate.tool.schema.spi.CommandAcceptanceException: Error executing DDL " drop table Event" via JDBC Statement at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:67) at org.hibernate.tool.schema.internal.SchemaDropperImpl.applySqlString(SchemaDropperImpl.java:375) at org.hibernate.tool.schema.internal.SchemaDropperImpl.applySqlStrings(SchemaDropperImpl.java:359) at org.hibernate.tool.schema.internal.SchemaDropperImpl.dropFromMetadata(SchemaDropperImpl.java:241) at org.hibernate.tool.schema.internal.SchemaDropperImpl.performDrop(SchemaDropperImpl.java:154) at org.hibernate.tool.schema.internal.SchemaDropperImpl.doDrop(SchemaDropperImpl.java:126) at org.hibernate.tool.schema.internal.SchemaDropperImpl.doDrop(SchemaDropperImpl.java:112) at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.performDatabaseAction(SchemaManagementToolCoordinator.java:144) at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.process(SchemaManagementToolCoordinator.java:72) at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:310) at org.hibernate.boot.internal.SessionFactoryBuilderImpl.build(SessionFactoryBuilderImpl.java:467) at org.hibernate.testing.junit4.BaseNonConfigCoreFunctionalTestCase.buildResources(BaseNonConfigCoreFunctionalTestCase.java:158) at org.hibernate.testing.junit4.BaseNonConfigCoreFunctionalTestCase.startUp(BaseNonConfigCoreFunctionalTestCase.java:134) at sun.reflect.GeneratedMethodAccessor498.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.hibernate.testing.junit4.TestClassMetadata.performCallbackInvocation(TestClassMetadata.java:205) at org.hibernate.testing.junit4.TestClassMetadata.invokeCallback(TestClassMetadata.java:192) at org.hibernate.testing.junit4.TestClassMetadata.performCallbacks(TestClassMetadata.java:184) at org.hibernate.testing.junit4.TestClassMetadata.performBeforeClassCallbacks(TestClassMetadata.java:175) at org.hibernate.testing.junit4.BeforeClassCallbackHandler.evaluate(BeforeClassCallbackHandler.java:25) at org.hibernate.testing.junit4.AfterClassCallbackHandler.evaluate(AfterClassCallbackHandler.java:25) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.runTestClass(JUnitTestClassExecutor.java:106) at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:58) at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:38) at org.gradle.api.internal.tasks.testing.junit.AbstractJUnitTestClassProcessor.processTestClass(AbstractJUnitTestClassProcessor.java:66) at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51) at sun.reflect.GeneratedMethodAccessor46.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24) at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32) at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93) at com.sun.proxy.$Proxy2.processTestClass(Unknown Source) at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:109) at sun.reflect.GeneratedMethodAccessor45.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35) at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24) at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:155) at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:137) at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404) at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63) at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55) at java.lang.Thread.run(Thread.java:748) Caused by: com.ibm.db2.jcc.am.SqlSyntaxErrorException: DB2 SQL Error: SQLCODE=-204, SQLSTATE=42704, SQLERRMC=DBALLO18.EVENT, DRIVER=4.24.92 at com.ibm.db2.jcc.am.b6.a(b6.java:810) at com.ibm.db2.jcc.am.b6.a(b6.java:66) at com.ibm.db2.jcc.am.b6.a(b6.java:140) at com.ibm.db2.jcc.am.k3.c(k3.java:2817) at com.ibm.db2.jcc.am.k3.d(k3.java:2801) at com.ibm.db2.jcc.am.k3.b(k3.java:2161) at com.ibm.db2.jcc.t4.ab.k(ab.java:445) at com.ibm.db2.jcc.t4.ab.c(ab.java:104) at com.ibm.db2.jcc.t4.p.b(p.java:38) at com.ibm.db2.jcc.t4.av.h(av.java:124) at sun.reflect.GeneratedMethodAccessor290.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.ibm.db2.jcc.am.k3.ak(k3.java:2156) at com.ibm.db2.jcc.am.k3.a(k3.java:3359) at com.ibm.db2.jcc.am.k3.e(k3.java:1124) at com.ibm.db2.jcc.am.k3.execute(k3.java:1105) at sun.reflect.GeneratedMethodAccessor266.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.hibernate.test.util.jdbc.PreparedStatementSpyConnectionProvider.lambda$null$1(PreparedStatementSpyConnectionProvider.java:115) at com.ibm.db2.jcc.am.k3.execute(k3.java:1100) at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:54) ... 50 more 08:02:00,785 DEBUG SQL:94 - create table Event ( id bigint not null, name varchar(255), primary key (id) ) Hibernate: create table Event ( id bigint not null, name varchar(255), primary key (id) ) 08:02:00,786 INFO access:47 - HHH10001501: Connection obtained from JdbcConnectionAccess [org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@75334abb] for (non-JTA) DDL execution was not in auto-commit mode; the Connection 'local transaction' will be committed and the Connection will be set into auto-commit mode. 08:02:00,950 INFO SchemaCreatorImpl:489 - HHH000476: Executing import script 'org.hibernate.tool.schema.internal.exec.ScriptSourceInputNonExistentImpl@76e2b5a2' 08:02:00,953 INFO CustomRunner:123 - Test: testSessionFactorySetting org.hibernate.test.jdbc.internal.SessionJdbcBatchTest > testSessionFactorySetting STANDARD_OUT 08:02:00,953 DEBUG StatisticsInitiator:101 - Statistics initialized [enabled=false] 08:02:00,955 DEBUG SQL:94 - insert into Event (name, id) values (?, ?) Hibernate: insert into Event (name, id) values (?, ?) 08:02:00,957 TRACE BasicBinder:65 - binding parameter [1] as [VARCHAR] - [Event 0] 08:02:00,959 TRACE BasicBinder:65 - binding parameter [2] as [BIGINT] - [0] 08:02:09,189 INFO QueryTranslatorFactoryInitiator:47 - HHH000397: Using ASTQueryTranslatorFactory 08:02:09,189 DEBUG QueryTranslatorImpl:287 - parse() - HQL: delete from org.hibernate.test.jdbc.internal.SessionJdbcBatchTest$Event 08:02:09,190 DEBUG ErrorTracker:97 - throwQueryException() : no errors 08:02:09,190 DEBUG QueryTranslatorImpl:308 - --- HQL AST --- \-[DELETE] Node: 'delete' \-[FROM] Node: 'FROM' \-[RANGE] Node: 'RANGE' \-[DOT] Node: '.' +-[DOT] Node: '.' | +-[DOT] Node: '.' | | +-[DOT] Node: '.' | | | +-[DOT] Node: '.' | | | | +-[IDENT] Node: 'org' | | | | \-[IDENT] Node: 'hibernate' | | | \-[IDENT] Node: 'test' | | \-[IDENT] Node: 'jdbc' | \-[IDENT] Node: 'internal' \-[IDENT] Node: 'SessionJdbcBatchTest$Event' 08:02:09,190 DEBUG FromElement:146 - FromClause{level=1} : org.hibernate.test.jdbc.internal.SessionJdbcBatchTest$Event (<no alias>) -> sessionjdb0_ 08:02:09,190 DEBUG QueryTranslatorImpl:274 - --- SQL AST --- \-[DELETE] DeleteStatement: 'delete' querySpaces (Event) \-[FROM] FromClause: 'FROM' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[], fromElementByTableAlias=[sessionjdb0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]} \-[FROM_FRAGMENT] FromElement: 'Event' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=Event,tableAlias=sessionjdb0_,origin=null,columns={,className=org.hibernate.test.jdbc.internal.SessionJdbcBatchTest$Event}} 08:02:09,190 DEBUG ErrorTracker:97 - throwQueryException() : no errors 08:02:09,191 DEBUG ErrorTracker:97 - throwQueryException() : no errors 08:02:09,191 DEBUG SQL:94 - delete from Event Hibernate: delete from Event 08:02:09,206 INFO StatisticalLoggingSessionEventListener:258 - Session Metrics { 1018795354 nanoseconds spent acquiring 1 JDBC connections; 335675 nanoseconds spent releasing 1 JDBC connections; 1710880 nanoseconds spent preparing 1 JDBC statements; 9820411 nanoseconds spent executing 1 JDBC statements; 0 nanoseconds spent executing 0 JDBC batches; 0 nanoseconds spent performing 0 L2C puts; 0 nanoseconds spent performing 0 L2C hits; 0 nanoseconds spent performing 0 L2C misses; 0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections); 4067 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections) } org.hibernate.test.jdbc.internal.SessionJdbcBatchTest > testSessionFactorySetting FAILED java.lang.StackOverflowError org.hibernate.test.jdbc.internal.SessionJdbcBatchTest STANDARD_OUT 08:02:09,207 INFO CustomRunner:123 - Test: testSessionSettingOverridesSessionFactorySetting org.hibernate.test.jdbc.internal.SessionJdbcBatchTest > testSessionSettingOverridesSessionFactorySetting STANDARD_OUT 08:02:09,209 DEBUG SQL:94 - insert into Event (name, id) values (?, ?) Hibernate: insert into Event (name, id) values (?, ?) 08:02:09,213 TRACE BasicBinder:65 - binding parameter [1] as [VARCHAR] - [Event 0] 08:02:09,213 TRACE BasicBinder:65 - binding parameter [2] as [BIGINT] - [5] 08:02:18,871 DEBUG SQL:94 - delete from Event Hibernate: delete from Event 08:02:18,885 INFO StatisticalLoggingSessionEventListener:258 - Session Metrics { 17691886 nanoseconds spent acquiring 1 JDBC connections; 404266 nanoseconds spent releasing 1 JDBC connections; 1531567 nanoseconds spent preparing 1 JDBC statements; 5896581 nanoseconds spent executing 1 JDBC statements; 0 nanoseconds spent executing 0 JDBC batches; 0 nanoseconds spent performing 0 L2C puts; 0 nanoseconds spent performing 0 L2C hits; 0 nanoseconds spent performing 0 L2C misses; 0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections); 13735 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections) } org.hibernate.test.jdbc.internal.SessionJdbcBatchTest > testSessionSettingOverridesSessionFactorySetting FAILED java.lang.StackOverflowError org.hibernate.test.jdbc.internal.SessionJdbcBatchTest STANDARD_OUT 08:02:18,889 INFO SchemaDropperImpl$DelayedDropActionImpl:524 - HHH000477: Starting delayed evictData of schema as part of SessionFactory shut-down' 08:02:18,889 DEBUG SQL:94 - drop table Event Hibernate: drop table Event 08:02:18,890 INFO access:47 - HHH10001501: Connection obtained from JdbcConnectionAccess [org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@52a9222d] for (non-JTA) DDL execution was not in auto-commit mode; the Connection 'local transaction' will be committed and the Connection will be set into auto-commit mode.

attached call stack of StackOverlowError

Environment

None

Status

Assignee

Vlad Mihalcea

Reporter

Martin Šimka

Fix versions

Labels

backPortable

Backport?

Suitable for new contributors

None

Requires Release Note

None

Pull Request

None

backportDecision

None

backportReEvaluate

Components

Priority

Major