There is a huge performance difference between the old & new version.
Please run the attached class BatchMain. Configure PostgreSQL connection details as appropriate.
*4.3.10 select took : 506762 ms* *5.4.2 select took : 916733 ms*
Full Log
*Hibernate 5.4.2 log*
C:\\jdk11.0.3_7\\bin\\java.exe -javaagent:C:\\ideaIC-2019.1.2-jbr11.win\\lib\\idea_rt.jar=63001:C:\\ideaIC-2019.1.2-jbr11.win\\bin -Dfile.encoding=UTF-8 -classpath C:\\Users\\venswa\\Downloads\\Hibernate-master\\08_batch_new\\target\\classes;C:\\Users\\venswa\\.m2\\repository\\org\\hibernate\\hibernate-core\\5.4.2.Final\\hibernate-core-5.4.2.Final.jar;C:\\Users\\venswa\\.m2\\repository\\org\\jboss\\logging\\jboss-logging\\3.3.2.Final\\jboss-logging-3.3.2.Final.jar;C:\\Users\\venswa\\.m2\\repository\\javax\\persistence\\javax.persistence-api\\2.2\\javax.persistence-api-2.2.jar;C:\\Users\\venswa\\.m2\\repository\\org\\javassist\\javassist\\3.24.0-GA\\javassist-3.24.0-GA.jar;C:\\Users\\venswa\\.m2\\repository\\net\\bytebuddy\\byte-buddy\\1.9.10\\byte-buddy-1.9.10.jar;C:\\Users\\venswa\\.m2\\repository\\antlr\\antlr\\2.7.7\\antlr-2.7.7.jar;C:\\Users\\venswa\\.m2\\repository\\org\\jboss\\spec\\javax\\transaction\\jboss-transaction-api_1.2_spec\\1.1.1.Final\\jboss-transaction-api_1.2_spec-1.1.1.Final.jar;C:\\Users\\venswa\\.m2\\repository\\org\\jboss\\jandex\\2.0.5.Final\\jandex-2.0.5.Final.jar;C:\\Users\\venswa\\.m2\\repository\\com\\fasterxml\\classmate\\1.3.4\\classmate-1.3.4.jar;C:\\Users\\venswa\\.m2\\repository\\javax\\activation\\javax.activation-api\\1.2.0\\javax.activation-api-1.2.0.jar;C:\\Users\\venswa\\.m2\\repository\\org\\dom4j\\dom4j\\2.1.1\\dom4j-2.1.1.jar;C:\\Users\\venswa\\.m2\\repository\\org\\hibernate\\common\\hibernate-commons-annotations\\5.1.0.Final\\hibernate-commons-annotations-5.1.0.Final.jar;C:\\Users\\venswa\\.m2\\repository\\javax\\xml\\bind\\jaxb-api\\2.3.1\\jaxb-api-2.3.1.jar;C:\\Users\\venswa\\.m2\\repository\\org\\glassfish\\jaxb\\jaxb-runtime\\2.3.1\\jaxb-runtime-2.3.1.jar;C:\\Users\\venswa\\.m2\\repository\\org\\glassfish\\jaxb\\txw2\\2.3.1\\txw2-2.3.1.jar;C:\\Users\\venswa\\.m2\\repository\\com\\sun\\istack\\istack-commons-runtime\\3.0.7\\istack-commons-runtime-3.0.7.jar;C:\\Users\\venswa\\.m2\\repository\\org\\jvnet\\staxex\\stax-ex\\1.8\\stax-ex-1.8.jar;C:\\Users\\venswa\\.m2\\repository\\com\\sun\\xml\\fastinfoset\\FastInfoset\\1.2.15\\FastInfoset-1.2.15.jar;C:\\Users\\venswa\\.m2\\repository\\org\\postgresql\\postgresql\\42.2.5\\postgresql-42.2.5.jar hibernate_example.batch.BatchMain Dec 17, 2019 10:10:55 AM org.hibernate.Version logVersion INFO: HHH000412: Hibernate Core \{5.4.2.Final} Dec 17, 2019 10:10:56 AM org.hibernate.annotations.common.reflection.java.JavaReflectionManager <clinit> INFO: HCANN000001: Hibernate Commons Annotations \{5.1.0.Final} Dec 17, 2019 10:10:56 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl configure WARN: HHH10001002: Using Hibernate built-in connection pool (not for production use\!) Dec 17, 2019 10:10:56 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl buildCreator INFO: HHH10001005: using driver \[org.postgresql.Driver] at URL \[jdbc😛ostgresql://localhost:5444/testnew?currentSchema=public] Dec 17, 2019 10:10:56 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl buildCreator INFO: HHH10001001: Connection properties: \{password=****, user=postgres} Dec 17, 2019 10:10:56 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl buildCreator INFO: HHH10001003: Autocommit mode: false Dec 17, 2019 10:10:56 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl$PooledConnections <init> INFO: HHH000115: Hibernate connection pool size: 1 (min=1) Dec 17, 2019 10:10:57 AM org.hibernate.dialect.Dialect <init> INFO: HHH000400: Using dialect: org.hibernate.dialect.PostgreSQLDialect Dec 17, 2019 10:10:57 AM org.hibernate.resource.transaction.backend.jdbc.internal.DdlTransactionIsolatorNonJtaImpl getIsolatedConnection INFO: HHH10001501: Connection obtained from JdbcConnectionAccess \[org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@95eb320] 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. Dec 17, 2019 10:10:57 AM org.hibernate.engine.transaction.jta.platform.internal.JtaPlatformInitiator initiateService INFO: HHH000490: Using JtaPlatform implementation: \[org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform] *===== time taken for insert===== 81077 ms* *select took : 916733 ms* Dec 17, 2019 10:27:36 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl$PoolState stop INFO: HHH10001008: Cleaning up connection pool \[jdbc😛ostgresql://localhost:5444/testnew?currentSchema=public] *===== total time taken ===== 999014 ms*
Process finished with exit code 0
===========================================================================
*Hibernate 4.3.10 log*
C:\\jdk11.0.3_7\\bin\\java.exe -javaagent:C:\\ideaIC-2019.1.2-jbr11.win\\lib\\idea_rt.jar=49647:C:\\ideaIC-2019.1.2-jbr11.win\\bin -Dfile.encoding=UTF-8 -classpath C:\\Users\\venswa\\Downloads\\Hibernate-master\\08_batch\\target\\classes;C:\\Users\\venswa\\.m2\\repository\\org\\hibernate\\hibernate-core\\4.3.10.Final\\hibernate-core-4.3.10.Final.jar;C:\\Users\\venswa\\.m2\\repository\\org\\jboss\\logging\\jboss-logging\\3.1.3.GA\\jboss-logging-3.1.3.GA.jar;C:\\Users\\venswa\\.m2\\repository\\org\\jboss\\logging\\jboss-logging-annotations\\1.2.0.Beta1\\jboss-logging-annotations-1.2.0.Beta1.jar;C:\\Users\\venswa\\.m2\\repository\\org\\jboss\\spec\\javax\\transaction\\jboss-transaction-api_1.2_spec\\1.0.0.Final\\jboss-transaction-api_1.2_spec-1.0.0.Final.jar;C:\\Users\\venswa\\.m2\\repository\\dom4j\\dom4j\\1.6.1\\dom4j-1.6.1.jar;C:\\Users\\venswa\\.m2\\repository\\xml-apis\\xml-apis\\1.0.b2\\xml-apis-1.0.b2.jar;C:\\Users\\venswa\\.m2\\repository\\org\\hibernate\\common\\hibernate-commons-annotations\\4.0.5.Final\\hibernate-commons-annotations-4.0.5.Final.jar;C:\\Users\\venswa\\.m2\\repository\\org\\hibernate\\javax\\persistence\\hibernate-jpa-2.1-api\\1.0.0.Final\\hibernate-jpa-2.1-api-1.0.0.Final.jar;C:\\Users\\venswa\\.m2\\repository\\org\\javassist\\javassist\\3.18.1-GA\\javassist-3.18.1-GA.jar;C:\\Users\\venswa\\.m2\\repository\\antlr\\antlr\\2.7.7\\antlr-2.7.7.jar;C:\\Users\\venswa\\.m2\\repository\\org\\jboss\\jandex\\1.1.0.Final\\jandex-1.1.0.Final.jar;C:\\Users\\venswa\\.m2\\repository\\org\\postgresql\\postgresql\\42.2.5\\postgresql-42.2.5.jar hibernate_example.batch.BatchMain Dec 17, 2019 10:29:25 AM org.hibernate.annotations.common.reflection.java.JavaReflectionManager <clinit> INFO: HCANN000001: Hibernate Commons Annotations \{4.0.5.Final} Dec 17, 2019 10:29:25 AM org.hibernate.Version logVersion INFO: HHH000412: Hibernate Core \{4.3.10.Final} Dec 17, 2019 10:29:25 AM org.hibernate.cfg.Environment <clinit> INFO: HHH000206: hibernate.properties not found Dec 17, 2019 10:29:25 AM org.hibernate.cfg.Environment buildBytecodeProvider INFO: HHH000021: Bytecode provider name : javassist Dec 17, 2019 10:29:25 AM org.hibernate.cfg.Configuration configure INFO: HHH000043: Configuring from resource: /hibernate.cfg.xml Dec 17, 2019 10:29:25 AM org.hibernate.cfg.Configuration getConfigurationInputStream INFO: HHH000040: Configuration resource: /hibernate.cfg.xml WARNING: An illegal reflective access operation has occurred WARNING: Illegal reflective access by org.dom4j.io.SAXContentHandler (file:/C:/Users/venswa/.m2/repository/dom4j/dom4j/1.6.1/dom4j-1.6.1.jar) to method com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser$LocatorProxy.getEncoding() WARNING: Please consider reporting this to the maintainers of org.dom4j.io.SAXContentHandler WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations WARNING: All illegal access operations will be denied in a future release Dec 17, 2019 10:29:25 AM org.hibernate.cfg.Configuration doConfigure INFO: HHH000041: Configured SessionFactory: null Dec 17, 2019 10:29:25 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl configure WARN: HHH000402: Using Hibernate built-in connection pool (not for production use\!) Dec 17, 2019 10:29:25 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl buildCreator INFO: HHH000401: using driver \[org.postgresql.Driver] at URL \[jdbc😛ostgresql://localhost:5444/testold?currentSchema=public] Dec 17, 2019 10:29:25 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl buildCreator INFO: HHH000046: Connection properties: \{password=****, user=postgres} Dec 17, 2019 10:29:25 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl buildCreator INFO: HHH000006: Autocommit mode: false Dec 17, 2019 10:29:25 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl configure INFO: HHH000115: Hibernate connection pool size: 1 (min=1) Dec 17, 2019 10:29:25 AM org.hibernate.dialect.Dialect <init> INFO: HHH000400: Using dialect: org.hibernate.dialect.PostgreSQLDialect Dec 17, 2019 10:29:25 AM org.hibernate.engine.jdbc.internal.LobCreatorBuilder useContextualLobCreation INFO: HHH000424: Disabling contextual LOB creation as createClob() method threw error : java.lang.reflect.InvocationTargetException Dec 17, 2019 10:29:25 AM org.hibernate.engine.transaction.internal.TransactionFactoryInitiator initiateService INFO: HHH000399: Using default transaction strategy (direct JDBC transactions) Dec 17, 2019 10:29:25 AM org.hibernate.hql.internal.ast.ASTQueryTranslatorFactory <init> INFO: HHH000397: Using ASTQueryTranslatorFactory Dec 17, 2019 10:29:26 AM org.hibernate.tool.hbm2ddl.SchemaUpdate execute INFO: HHH000228: Running hbm2ddl schema update Dec 17, 2019 10:29:26 AM org.hibernate.tool.hbm2ddl.SchemaUpdate execute INFO: HHH000102: Fetching database metadata Dec 17, 2019 10:29:26 AM org.hibernate.tool.hbm2ddl.SchemaUpdate execute INFO: HHH000396: Updating schema Dec 17, 2019 10:29:26 AM org.hibernate.tool.hbm2ddl.DatabaseMetadata getTableMetadata INFO: HHH000262: Table not found: BOOKS Dec 17, 2019 10:29:26 AM org.hibernate.tool.hbm2ddl.DatabaseMetadata getTableMetadata INFO: HHH000262: Table not found: BOOKS Dec 17, 2019 10:29:26 AM org.hibernate.tool.hbm2ddl.DatabaseMetadata getTableMetadata INFO: HHH000262: Table not found: BOOKS Dec 17, 2019 10:29:26 AM org.hibernate.tool.hbm2ddl.SchemaUpdate execute INFO: HHH000232: Schema update complete *===== time taken for insert===== 86174 ms* *select took : 506762 ms* Dec 17, 2019 10:39:19 AM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl stop INFO: HHH000030: Cleaning up connection pool \[jdbc😛ostgresql://localhost:5444/testold?currentSchema=public] *===== total time taken ===== 593134 ms*
Process finished with exit code 0
Test code
[https://github.com/ramanans/hibernate-perf-test/tree/master/08_batch|https://github.com/ramanans/hibernate-perf-test/tree/master/08_batch]
With other versions
4.3.10 ===== time taken for insert===== 22274 ms select took : 36388 ms ===== total time taken ===== 58954 ms
5.4.2 ===== time taken for insert===== 22592 ms select took : 41843 ms ===== total time taken ===== 65648 ms
5.4.10==== time taken for insert===== 22395 ms select took : 41416 ms ===== total time taken ===== 64656 ms
6.0.0.Alpha4 === time for insert===== 23555 ms select took : 34776 ms ===== total time taken ===== 59127 ms
|
|