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] |
|
