該程序一個接一個地執行數以萬計的連續插入。我從來沒有用過Hibernate。我得到的速度非常慢(如果我只是手動連接和執行SQL,速度要快10-12倍,根據許多hibernate教程,我的batch_size設置爲50)Hibernate批量大小混淆
這是一個來自單個插入的日誌 - 也許你能幫助我瞭解到底發生了什麼:
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
夢幻般的答案。如果我能讓你更多,我會。我設法解決了這個問題,不過謝謝! –
我想知道爲什麼在**遞增循環索引'i'之前刷新並清除會話**。我想你應該從'for'循環中刪除'i ++',並且如果條件爲'++ i%50 == 0'則更改。 (在Hibernate文檔中出錯?) – DylanYi
@dylanyi這只是一個例子。也許索引i與掃描源數組有關(請參閱record.setXXX:它從何處獲取數據?)。在處理數百萬條記錄時,在開始時刷新0並不會產生如此差異 –