Hibernate批量大小混乱 [英] Hibernate batch size confusion
问题描述
这是来自单一插入的日志 - 也许你可以帮助我理解到底发生了什么:
START INSERT
11:02:56.121 [main] DEBUG org.hibernate.impl.SessionImpl - 打开会话时间戳:13106053761
11:02:56.121 [main] DEBUG ohtransaction.JDBCTransaction - begin
11:02 :56.121 [main] DEBUG org.hibernate.jdbc.ConnectionManager - 打开JDBC连接
11:02:56.121 [main] TRACE ohcDriverManagerConnectionProvider - to od
11:02:56.121 [main] TRACE ohcDriverManagerConnectionProvider - 使用池连接的JDBC,池大小:0
11:02:56.121 [main] DEBUG ohtransaction.JDBCTransaction - 当前自动提交状态:false
11:02:56.121 [main] TRACE org.hibernate.jdbc.JDBCContext - 事务开始后
11:02:56.121 [main] TRACE org.hibernate.impl.SessionImpl - 将刷新模式设置为:MANUAL
11:02:56.121 [main] TRACE ohedef.DefaultLoadEventListener - loadi ng entity:[com.xyzcompany.foo.edoi.ejb.msw000.MSW000Rec#component [keyW000] {keyW000 = F000 ADSUFC}]
11:02:56.121 [main] TRACE ohedef.DefaultLoadEventListener - 创建新代理对于实体
11:02:56.122 [main] TRACE ohedDefaultSaveOrUpdateEventListener - 保存瞬态实例
11:02:56.122 [main] DEBUG ohedef.AbstractSaveEventListener - 生成的标识符:component [keyW000] {keyW000 = F000 ADSUFC},使用策略:org.hibernate.id.CompositeNestedGeneratedValueGenerator
11:02:56.122 [main] TRACE ohedef.AbstractSaveEventListener - 保存[com.xyzcompany.foo.edoi.ejb.msw000.MSW000Rec#component [keyW000 ] {keyW000 = F000 ADSUFC}]
11:02:56.123 [主] TRACE ohedAbstractFlushing EventListener - 刷新会话
11:02:56.123 [main] DEBUG ohedAbstractFlushingEventListener - 处理刷新时间级联
11:02:56.123 [main] DEBUG ohedAbstractFlushingEventListener - 脏检查集合
11: 02:56.123 [main] TRACE ohedAbstractFlushingEventListener - 刷新实体并处理引用的集合
11:02:56.125 [main] TRACE ohedAbstractFlushingEventListener - 处理未引用的集合
11:02:56.125 [main] TRACE oh edAbstractFlushingEventListener - 调度集合删除/(重新)创建/更新
11:02:56.126 [main] DEBUG ohedAbstractFlushingEventListener - 刷新:1个插入,0更新,0删除62个对象
11:02: 56.126 [main] DEBUG ohedAbstractFlushingEventListener - 刷新:0(重新创建),0更新,0删除为0集合
11:02:56.132 [main] TRACE ohedAbstractFlushingEventListener - 执行刷新
11:02: 56.132 [main] TRACE org.hibernate.jdbc.ConnectionManager - 注册刷新开始
11:02:56.132 [主] TRACE ohpentity.AbstractEntityPersister - 插入实体:[com.xyzcompany.foo.edoi.ejb.msw000.MSW000Rec#component [keyW000] {keyW000 = F000 ADSUFC}]
11:02:56.132 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - 即将打开PreparedStatement(打开PreparedStatements:0,全局:0)
11:02:56.132 [main] DEBUG org.hibernate.SQL - 插入到MSW000(W000_DATA_REC,W000_FILE_FLAGS,KEY_W000)值(?,?,?)
11:02:56.132 [main] TRACE org.hibernate.jdbc.AbstractBatcher - 准备语句
11:02: 56.132 [主] TRACE ohpentity.AbstractEntityPersister - 脱水实体:[com.xyzcompany.foo.ed oi.ejb.msw000.MSW000Rec#component [keyW000] {keyW000 = F000 ADSUFC}]
11:02:56.132 [main] TRACE org.hibernate.type.StringType - 将'ADSUFCA'绑定到参数:1
11:02:56.132 [main] TRACE org.hibernate.type.StringType - 绑定到参数:'
11:02:56.132 [main] TRACE org.hibernate.type.StringType - binding'F000 ADSUFC'参数:3
11:02:56.132 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - 执行批量大小:1
11:02:56.133 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - 即将关闭PreparedStatement(打开PreparedStatements:1,全局:1)
11:02:56.133 [main] TRACE org。 hibernate.jdbc.AbstractBatcher - 关闭语句
11:02:56.133 [main] TRACE org.hibernate.jdbc.ConnectionManager - 注册刷新结束
11:02:56.133 [main] TRACE ohedAbstractFlushingEventListener - post flush
11:02:56.133 [main] DEBUG ohtransaction.JDBCTransaction - commit
11:02:56.133 [main] TRACE org.hibernate.impl.SessionImpl - 自动刷新会话
11:02:56.133 [main] TRACE org.hibernate.jdbc.JDBCContext - 事务完成前
11:02:56.133 [main] TRACE org.hibernate.impl.SessionImpl - 交易完成前
11:02:56.133 [main] DEBUG ohtransaction.JDBCTransaction - 提交JDBC连接
11:02 :56.133 [主] TRACE org.hibernate.jdbc.JDBCContext - 事务完成后
11:02:56.133 [main] DEBUG org.hibernate.jdbc.ConnectionManager - 使用on_close连接释放模式在会话上完成事务;一定要关闭会话以释放JDBC资源!
11:02:56.133 [main] TRACE org.hibernate.impl.SessionImpl - 事务完成后
11:02:56.133 [main] TRACE org.hibernate.impl.SessionImpl - 关闭会话
11:02:56.133 [main] TRACE org.hibernate.jdbc.ConnectionManager - 执行清理
11:02:56.133 [main] DEBUG org.hibernate.jdbc.ConnectionManager - 释放JDBC连接[(打开PreparedStatements:0 ,全局:0)(打开ResultSets:0,全局:0)]
11:02:56.133 [主] TRACE ohcDriverManagerConnectionProvider - 返回连接池,池大小:1
11:02:56.133 [main] TRACE org.hibernate.jdbc.JDBCContext - 事务完成后
11:02:56.133 [main] DEBUG org.hibernate.jdbc.ConnectionManager - on_close连接释放模式;一定要关闭会话以释放JDBC资源!
11:02:56.134 [main] TRACE org.hibernate.impl.SessionImpl - 交易完成后
FINISH INSERT
$ b当你调用 session.save()
时,hibernate会生成一个INSERT SQL。这个INSERT SQL将被追加以在刷新期间发布给DB(即 session.flush()
)。
在刷新期间,如果 hibernate.jdbc.batch_size
设置为某个非零值,Hibernate将使用在JDBC2 API中引入的批处理功能向数据库发出批量插入SQL。例如,如果 save()
> 100条记录,并且 hibernate.jdbc 。 batch_size
设置为50.在刷新过程中,不是发出以下SQL 100次:
插入到TableA(id,fields)的值(1,'val1');
插入TableA(id,fields)值(2,'val2');
插入到TableA(id,fields)值(3,'val3');
.........................
插入TableA(id,fields)的值(100,'val100');
Hiberate会将它们分组为50个,并且只向数据库发出2个SQL,如下所示:
插入TableA(id,fields)values(1,'val1'),(2,'val2'),( 3,'val3'),(4,'val4'),......,(50,'val50')
插入到TableA(id,fields)值(51,'val51')中, (52,'val52'),(53,'val53'),(54,'val54'),......,(100,'val100')
请注意,如果插入表的主键是 GenerationType.Identity
从您的日志中: save()
只有一条记录,然后 flush()
,所以每次刷新只能处理一个附加的INSERT SQL。这就是为什么Hibernate无法帮助您批量插入,因为只有一个INSERT SQL需要处理。在调用 flush()
之前,您应该 save()
达到一定数量的记录,而不是调用<$ c $对于每个 save()
,c> flush()。
批量插入的最佳实践如下所示:
Session session = sessionFactory.openSession();
Transaction tx = session.beginTransaction();
for(int i = 0; i <888888; i ++){
TableA record = new TableA();
record.setXXXX();
session.save(记录)
if(i%50 == 0){// 50,与JDBC批量大小相同
//刷新一批插入并释放内存:
session.flush();
session.clear();
}
}
tx.commit();
session.close();
您可以批量保存并刷新记录。在每个批处理结束时,您应该清除持久化上下文以释放一些内存,以防止每个持久对象放入第一级缓存(JVM的内存)时耗尽内存。您也可以禁用二级缓存以减少不必要的开销。
参考:
This program does tens of thousands of consecutive inserts one after the other. I've never used Hibernate before. I'm getting extremely slow performance (if I just connect and execute the SQL manually I am 10-12x quicker. My batch_size is set to 50 as per many hibernate tutorials.
Here is a log from a single insert - perhaps you could help me understand exactly what is happening:
START INSERT
11:02:56.121 [main] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13106053761
11:02:56.121 [main] DEBUG o.h.transaction.JDBCTransaction - begin
11:02:56.121 [main] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
11:02:56.121 [main] TRACE o.h.c.DriverManagerConnectionProvider - total checked-out connections: 0
11:02:56.121 [main] TRACE o.h.c.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
11:02:56.121 [main] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
11:02:56.121 [main] TRACE org.hibernate.jdbc.JDBCContext - after transaction begin
11:02:56.121 [main] TRACE org.hibernate.impl.SessionImpl - setting flush mode to: MANUAL
11:02:56.121 [main] TRACE o.h.e.def.DefaultLoadEventListener - loading entity: [com.xyzcompany.foo.edoi.ejb.msw000.MSW000Rec#component[keyW000]{keyW000=F000 ADSUFC}]
11:02:56.121 [main] TRACE o.h.e.def.DefaultLoadEventListener - creating new proxy for entity
11:02:56.122 [main] TRACE o.h.e.d.DefaultSaveOrUpdateEventListener - saving transient instance
11:02:56.122 [main] DEBUG o.h.e.def.AbstractSaveEventListener - generated identifier: component[keyW000]{keyW000=F000 ADSUFC}, using strategy: org.hibernate.id.CompositeNestedGeneratedValueGenerator
11:02:56.122 [main] TRACE o.h.e.def.AbstractSaveEventListener - saving [com.xyzcompany.foo.edoi.ejb.msw000.MSW000Rec#component[keyW000]{keyW000=F000 ADSUFC}]
11:02:56.123 [main] TRACE o.h.e.d.AbstractFlushingEventListener - flushing session
11:02:56.123 [main] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
11:02:56.123 [main] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
11:02:56.123 [main] TRACE o.h.e.d.AbstractFlushingEventListener - Flushing entities and processing referenced collections
11:02:56.125 [main] TRACE o.h.e.d.AbstractFlushingEventListener - Processing unreferenced collections
11:02:56.125 [main] TRACE o.h.e.d.AbstractFlushingEventListener - Scheduling collection removes/(re)creates/updates
11:02:56.126 [main] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 1 insertions, 0 updates, 0 deletions to 62 objects
11:02:56.126 [main] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
11:02:56.132 [main] TRACE o.h.e.d.AbstractFlushingEventListener - executing flush
11:02:56.132 [main] TRACE org.hibernate.jdbc.ConnectionManager - registering flush begin
11:02:56.132 [main] TRACE o.h.p.entity.AbstractEntityPersister - Inserting entity: [com.xyzcompany.foo.edoi.ejb.msw000.MSW000Rec#component[keyW000]{keyW000=F000 ADSUFC}]
11:02:56.132 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
11:02:56.132 [main] DEBUG org.hibernate.SQL - insert into MSW000 (W000_DATA_REC, W000_FILE_FLAGS, KEY_W000) values (?, ?, ?)
11:02:56.132 [main] TRACE org.hibernate.jdbc.AbstractBatcher - preparing statement
11:02:56.132 [main] TRACE o.h.p.entity.AbstractEntityPersister - Dehydrating entity: [com.xyzcompany.foo.edoi.ejb.msw000.MSW000Rec#component[keyW000]{keyW000=F000 ADSUFC}]
11:02:56.132 [main] TRACE org.hibernate.type.StringType - binding ' ADSUFCA ' to parameter: 1
11:02:56.132 [main] TRACE org.hibernate.type.StringType - binding ' ' to parameter: 2
11:02:56.132 [main] TRACE org.hibernate.type.StringType - binding 'F000 ADSUFC' to parameter: 3
11:02:56.132 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - Executing batch size: 1
11:02:56.133 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
11:02:56.133 [main] TRACE org.hibernate.jdbc.AbstractBatcher - closing statement
11:02:56.133 [main] TRACE org.hibernate.jdbc.ConnectionManager - registering flush end
11:02:56.133 [main] TRACE o.h.e.d.AbstractFlushingEventListener - post flush
11:02:56.133 [main] DEBUG o.h.transaction.JDBCTransaction - commit
11:02:56.133 [main] TRACE org.hibernate.impl.SessionImpl - automatically flushing session
11:02:56.133 [main] TRACE org.hibernate.jdbc.JDBCContext - before transaction completion
11:02:56.133 [main] TRACE org.hibernate.impl.SessionImpl - before transaction completion
11:02:56.133 [main] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
11:02:56.133 [main] TRACE org.hibernate.jdbc.JDBCContext - after transaction completion
11:02:56.133 [main] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
11:02:56.133 [main] TRACE org.hibernate.impl.SessionImpl - after transaction completion
11:02:56.133 [main] TRACE org.hibernate.impl.SessionImpl - closing session
11:02:56.133 [main] TRACE org.hibernate.jdbc.ConnectionManager - performing cleanup
11:02:56.133 [main] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
11:02:56.133 [main] TRACE o.h.c.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
11:02:56.133 [main] TRACE org.hibernate.jdbc.JDBCContext - after transaction completion
11:02:56.133 [main] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
11:02:56.134 [main] TRACE org.hibernate.impl.SessionImpl - after transaction completion
FINISH INSERT
When you call session.save()
, hibernate will generate an INSERT SQL. This INSERT SQL will be appended to be issued to the DB during flushing (i.e session.flush()
) .
During flushing, if hibernate.jdbc.batch_size
is set to some non-zero value, Hibernate will use the batching feature introduced in the JDBC2 API to issue the batch insert SQL to the DB .
For example , if you save()
100 records and your hibernate.jdbc.batch_size
is set to 50. During flushing, instead of issue the following SQL 100 times :
insert into TableA (id , fields) values (1, 'val1');
insert into TableA (id , fields) values (2, 'val2');
insert into TableA (id , fields) values (3, 'val3');
.........................
insert into TableA (id , fields) values (100, 'val100');
Hiberate will group them in batches of 50 , and only issue 2 SQL to the DB, like this:
insert into TableA (id , fields) values (1, 'val1') , (2, 'val2') ,(3, 'val3') ,(4, 'val4') ,......,(50, 'val50')
insert into TableA (id , fields) values (51, 'val51') , (52, 'val52') ,(53, 'val53') ,(54, 'val54'),...... ,(100, 'val100')
Please note that Hibernate would disable insert batching at the JDBC level transparently if the primary key of the inserting table isGenerationType.Identity
.
From your log: you save()
only one record and then flush()
, so there is only one appending INSERT SQL to be processed for every flush. That's why Hibernate cannot help you to batch inserting as there is only one INSERT SQL to be processed. You should save()
up to the certain amount of records before calling flush()
instead of calling flush()
for every save()
.
The best practise of batch inserting is something like this:
Session session = sessionFactory.openSession();
Transaction tx = session.beginTransaction();
for ( int i=0; i<888888; i++ ) {
TableA record = new TableA();
record.setXXXX();
session.save(record)
if ( i % 50 == 0 ) { //50, same as the JDBC batch size
//flush a batch of inserts and release memory:
session.flush();
session.clear();
}
}
tx.commit();
session.close();
You save and flush the records batch by batch. In the end of each batch you should clear the persistence context to release some memory to prevent memory exhaustion as every persistent object is placed into the first level cache (your JVM's memory). You could also disable the second-level cache to reduce the unnecessary overhead.
Reference:
- Official Hibernate Documentation : Chapter 14. Batch processing
- Hibernate Batch Processing – Why you may not be using it. (Even if you think you are)
这篇关于Hibernate批量大小混乱的文章就介绍到这了,希望我们推荐的答案对大家有所帮助,也希望大家多多支持IT屋!