Description
Attachments
- 13 May 2017, 03:07 PM
- 19 Apr 2017, 05:19 PM
Activity
Chris Cranford May 17, 2017 at 7:49 PM
Chris Cranford May 15, 2017 at 4:42 PM(edited)
Was the SQLServerDialect
something being driven by the configuration or was that something that Hibernate was defaulting? We added a fix in https://hibernate.atlassian.net/browse/HHH-11220#icft=HHH-11220 to adjust the dialect resolution for SQLServer which is why I ask how the legacy dialect was being influenced because that was fixed in 5.2.5 (and your logs show 5.2.10).
I'll change my test environment to force the legacy dialect to reproduce. Ideally we'd prefer using the legacy dialects on newer database platforms to not be broken, e.g. they should be backward compatible but with just less features or less than optimal choices for the environment where possible but given certain conditions, that may not always work out as we intend.
Brett Wooldridge May 15, 2017 at 3:59 PM(edited)
Just ran the oltpbenchmark JPAB test again on my Hibernate 5 branch, here is the output (using the mssql-jdbc-6.1.6.jre8-preview.jar driver):
~/Documents/dev/oltpbench-hibernate5$ ./oltpbenchmark -b jpab -config config/sample_jpab_config.xml --create=false --load=false --execute=true --histograms -s 5 -o jpab-newer
00:54:16,874 (DBWorkload.java:259) INFO - ======================================================================
Benchmark: JPAB {com.oltpbenchmark.benchmarks.jpab.JPABBenchmark}
Configuration: config/sample_jpab_config.xml
Type: SQLSERVER
Driver: com.microsoft.sqlserver.jdbc.SQLServerDriver
URL: jdbc:sqlserver://localhost:1433;databaseName=master
Isolation: TRANSACTION_SERIALIZABLE
Scale Factor: 1000000.0
00:54:16,876 (DBWorkload.java:260) INFO - ======================================================================
00:54:16,991 (DBWorkload.java:790) INFO - Creating 10 virtual terminals...
00:54:17,147 (LogHelper.java:31) INFO - HHH000204: Processing PersistenceUnitInfo [
name: Hibernate-MySQL-server
...]
00:54:17,250 (Version.java:45) INFO - HHH000412: Hibernate Core {5.2.10.Final}
00:54:17,251 (Environment.java:213) INFO - HHH000206: hibernate.properties not found
00:54:17,300 (JavaReflectionManager.java:66) INFO - HCANN000001: Hibernate Commons Annotations {5.0.1.Final}
00:54:17,446 (ConnectionProviderInitiator.java:122) INFO - HHH000130: Instantiating explicit connection provider: org.hibernate.hikaricp.internal.HikariCPConnectionProvider
[main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
[main] INFO com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Driver does not support get/set network timeout for connections. (This operation is not supported.)
[main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed.
00:54:17,926 (Dialect.java:157) INFO - HHH000400: Using dialect: org.hibernate.dialect.SQLServerDialect
00:54:18,247 (TableGenerator.java:468) INFO - HHH000398: Explicit segment value for id generator [hibernate_sequences.sequence_name] suggested; using default [CollectionPerson]
00:54:18,252 (TableGenerator.java:468) INFO - HHH000398: Explicit segment value for id generator [hibernate_sequences.sequence_name] suggested; using default [PersonBase]
00:54:18,253 (TableGenerator.java:468) INFO - HHH000398: Explicit segment value for id generator [hibernate_sequences.sequence_name] suggested; using default [Person]
00:54:18,253 (TableGenerator.java:468) INFO - HHH000398: Explicit segment value for id generator [hibernate_sequences.sequence_name] suggested; using default [IndexedPerson]
00:54:18,267 (SessionFactoryBuilderImpl.java:868) WARN - HHH90000023: Encountered use of deprecated Connection handling settings [hibernate.connection.acquisition_mode]or [hibernate.connection.release_mode]; use [hibernate.connection.handling_mode] instead
00:54:36,220 (DBWorkload.java:795) INFO - Launching the JPAB Benchmark with 1 Phase...
00:54:36,261 (ThreadBench.java:325) INFO - PHASE START :: [Workload=JPAB] [Serial=false] [Time=10] [Rate=10000] [Arrival=REGULAR] [Ratios=[25.0, 25.0, 25.0, 25.0]] [ActiveWorkers=10]
00:54:36,262 (ThreadBench.java:472) INFO - MEASURE :: Warmup complete, starting measurements.
00:54:36,279 (QueryTranslatorFactoryInitiator.java:47) INFO - HHH000397: Using ASTQueryTranslatorFactory
00:54:36,396 (SqlExceptionHelper.java:129) WARN - SQL Error: 0, SQLState: S1093
00:54:36,396 (SqlExceptionHelper.java:131) ERROR - The index 2 is out of range.
00:54:36,396 (SqlExceptionHelper.java:129) WARN - SQL Error: 0, SQLState: S1093
00:54:36,396 (SqlExceptionHelper.java:131) ERROR - The index 2 is out of range.
00:54:36,397 (SqlExceptionHelper.java:129) WARN - SQL Error: 0, SQLState: S1093
00:54:36,397 (SqlExceptionHelper.java:131) ERROR - The index 2 is out of range.
00:54:36,397 (SqlExceptionHelper.java:129) WARN - SQL Error: 0, SQLState: S1093
00:54:36,398 (SqlExceptionHelper.java:131) ERROR - The index 2 is out of range.
00:54:36,398 (SqlExceptionHelper.java:129) WARN - SQL Error: 0, SQLState: S1093
00:54:36,398 (SqlExceptionHelper.java:131) ERROR - The index 2 is out of range.
00:54:36,396 (SqlExceptionHelper.java:129) WARN - SQL Error: 0, SQLState: S1093
00:54:36,398 (SqlExceptionHelper.java:131) ERROR - The index 2 is out of range.
00:54:36,397 (SqlExceptionHelper.java:129) WARN - SQL Error: 0, SQLState: S1093
00:54:36,399 (SqlExceptionHelper.java:131) ERROR - The index 2 is out of range.
00:54:36,400 (SqlExceptionHelper.java:129) WARN - SQL Error: 0, SQLState: S1093
00:54:36,400 (SqlExceptionHelper.java:131) ERROR - The index 2 is out of range.
00:54:36,397 (SqlExceptionHelper.java:129) WARN - SQL Error: 0, SQLState: S1093
00:54:36,400 (SqlExceptionHelper.java:131) ERROR - The index 2 is out of range.
00:54:36,397 (SqlExceptionHelper.java:129) WARN - SQL Error: 0, SQLState: S1093
00:54:36,400 (SqlExceptionHelper.java:131) ERROR - The index 2 is out of range.
00:54:36,406 (Worker.java:492) ERROR - Fatal error when invoking Retrieve/02
javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: could not execute query
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:147)
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:155)
at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1423)
at org.hibernate.query.Query.getResultList(Query.java:146)
at com.oltpbenchmark.benchmarks.jpab.tests.Test.retireveEntities(Test.java:409)
at com.oltpbenchmark.benchmarks.jpab.tests.Test.doAction(Test.java:280)
at com.oltpbenchmark.benchmarks.jpab.procedures.Retrieve.run(Retrieve.java:51)
at com.oltpbenchmark.benchmarks.jpab.JPABWorker.retrieveTest(JPABWorker.java:75)
at com.oltpbenchmark.benchmarks.jpab.JPABWorker.executeWork(JPABWorker.java:58)
at com.oltpbenchmark.api.Worker.doWork(Worker.java:380)
at com.oltpbenchmark.api.Worker.run(Worker.java:290)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.hibernate.exception.GenericJDBCException: could not execute query
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111)
at org.hibernate.loader.Loader.doList(Loader.java:2618)
at org.hibernate.loader.Loader.doList(Loader.java:2598)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2430)
at org.hibernate.loader.Loader.list(Loader.java:2425)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:502)
at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:379)
at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216)
at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1488)
at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1445)
at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1414)
... 9 more
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: The index 2 is out of range.
at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDriverError(SQLServerException.java:227)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.setterGetParam(SQLServerPreparedStatement.java:918)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.setValue(SQLServerPreparedStatement.java:938)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.setInt(SQLServerPreparedStatement.java:1422)
at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.setInt(HikariProxyPreparedStatement.java)
at org.hibernate.dialect.pagination.AbstractLimitHandler.bindLimitParameters(AbstractLimitHandler.java:156)
at org.hibernate.dialect.pagination.AbstractLimitHandler.bindLimitParametersAtEndOfQuery(AbstractLimitHandler.java:128)
at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1958)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1909)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1887)
at org.hibernate.loader.Loader.doQuery(Loader.java:932)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:349)
at org.hibernate.loader.Loader.doList(Loader.java:2615)
... 18 more
java.lang.RuntimeException: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: could not execute query
at com.oltpbenchmark.api.Worker.doWork(Worker.java:493)
at com.oltpbenchmark.api.Worker.run(Worker.java:290)
at java.lang.Thread.run(Thread.java:745)
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: could not execute query
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:147)
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:155)
at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProduce00:54:36,407 (Worker.java:492) ERROR - Fatal error when invoking Retrieve/02
javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: could not execute query
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:147)
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:155)
at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1423)
at org.hibernate.query.Query.getResultList(Query.java:146)
at com.oltpbenchmark.benchmarks.jpab.tests.Test.retireveEntities(Test.java:409)
at com.oltpbenchmark.benchmarks.jpab.tests.Test.doAction(Test.java:280)
at com.oltpbenchmark.benchmarks.jpab.procedures.Retrieve.run(Retrieve.java:51)
at com.oltpbenchmark.benchmarks.jpab.JPABWorker.retrieveTest(JPABWorker.java:75)
at com.oltpbenchmark.benchmarks.jpab.JPABWorker.executeWork(JPABWorker.java:58)
at com.oltpbenchmark.api.Worker.doWork(Worker.java:380)
at com.oltpbenchmark.api.Worker.rundQuery.java:1423)
at org.hibernate.query.Query.getResultList(Query.java:146)
at com.oltpbenchmark.benchmarks.jpab.tests.Test.retireveEntities(Test.java:409)
at com.oltpbenchmark.benchmarks.jpab.tests.Test.doAction(Test.java:280)
at com.oltpbenchmark.benchmarks.jpab.procedures.Retrieve.run(Retrieve.java:51)
at com.oltpbenchmark.benchmarks.jpab.JPABWorker.retrieveTest(JPABWorker.java:75)
at com.oltpbenchmark.benchmarks.jpab.JPABWorker.executeWork(JPABWorker.java:58)
at com.oltpbenchmark.api.Worker.doWork(Worker.java:380)
... 2 more
Caused by: org.hibernate.exception.GenericJDBCException: could not execute query
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111)
at org.hibernate.loader.Loader.doList(Loader.java:2618)
at org.hibernate.loader.Loader.doList(Loader.java:2598)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2430)
at org.hibernate.loader.Loader.list(Loader.java:2425)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:502)
at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:379)
at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216)
at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1488)
at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1445)
at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1414)
... 9 more
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: The index 2 is out of range.
at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDriverError(SQLServerException.java:227)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.setterGetParam(SQLServerPreparedStatement.java:918)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.setValue(SQLServerPreparedStatement.java:938)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.setInt(SQLServerPreparedStatement.java:1422)
at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.setInt(HikariProxyPreparedStatement.java)
at org.hibernate.dialect.pagination.AbstractLimitHandler.bindLimitParameters(AbstractLimitHandler.java:156)
at org.hibernate.dialect.pagination.AbstractLimitHandler.bindLimitParametersAtEndOfQuery(AbstractLimitHandler.java:128)
at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1958)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1909)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1887)(Worker.java:290)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.hibernate.exception.GenericJDBCException: could not execute query
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111)
at org.hibernate.loader.Loader.doList(Loader.java:2618)
at org.hibernate.loader.Loader.doList(Loader.java:2598)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2430)
at org.hibernate.loader.Loader.list(Loader.java:2425)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:502)
at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:379)
at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216)
at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1488)
at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1445)
at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1414)
... 9 more
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: The index 2 is out of range.
at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDriverError(SQLServerException.java:227)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.setterGetParam(SQLServerPreparedStatement.java:918)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.setValue(SQLServerPreparedStatement.java:938)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.setInt(SQLServerPreparedStatement.java:1422)
at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.setInt(HikariProxyPreparedStatement.java)
at org.hibernate.dialect.pagination.AbstractLimitHandler.bindLimitParameters(AbstractLimitHandler.java:156)
at org.hibernate.dialect.pagination.AbstractLimitHandler.bindLimitParametersAtEndOfQuery(AbstractLimitHandler.java:128)
at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1958)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1909)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1887)
at org.hibernate.loader.Loader.doQuery(Loader.java:932)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:349)
at org.hibernate.loader.Loader.doList(Loader.java:2615)
... 18 more
at org.hibernate.loader.Loader.doQuery(Loader.java:932)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:349)
at org.hibernate.loader.Loader.doList(Loader.java:2615)
... 18 more
...
Is the issue that the dialect is SQLServerDialect and not SQLServer2012Dialect?
Answering my own question: Yes. Changing the benchmark code to use SQLServer2012Dialect removes the issue.
Brett Wooldridge May 15, 2017 at 3:45 PM(edited)
Chris Cranford, I'll make another run soon to see if I can reproduce. I was running the v6.1.6 driver. And I was using my fork/branch of the oltpbenchmark wherein I upgraded the Hibernate from v3 to v4.3.11.
EDIT: Sorry, mis-typed. Hibernate v4.3.11 works. It is my Hibernate 5 branch that showed the issue (again with the v6.1.6 driver).
Chris Cranford May 15, 2017 at 1:12 PM
@Brett Wooldridge, I just used the following:
09:10:58,560 DEBUG JdbcEnvironmentInitiator:83 - Driver ->
name : Microsoft JDBC Driver 6.1 for SQL Server
version : 6.1.0.0
major : 6
minor : 1
I didn't run into any issues against a Microsoft SQL Server 2016 environment using SQLServer2012Dialect with the 6.1.0.0 driver. Thoughts?
@Brett Wooldridge, explicitly specifying the
SQLSeverDialect
rather than using the dialect resolver strategy does indeed throw the exception. I've tracked it down to a code change inTopLimitHandler
that I'll address now.