Chương trình này thực hiện hàng chục nghìn lần chèn liên tiếp sau cái khác. Tôi chưa bao giờ sử dụng Hibernate trước đây. Tôi nhận được hiệu suất cực kỳ chậm (nếu tôi chỉ kết nối và thực hiện SQL bằng tay tôi nhanh hơn 10-12x. Batch_size của tôi được đặt thành 50 theo nhiều hướng dẫn hibernate.Sự nhầm lẫn kích thước hàng loạt Hibernate
Đây là nhật ký từ một chèn đơn lẻ bạn có thể giúp tôi hiểu chính xác những gì đang xảy ra:.
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
Câu trả lời tuyệt vời. Nếu tôi có thể upvote bạn nhiều hơn tôi sẽ. Tôi đã xoay xở để giải quyết nó, nhưng dù sao cũng được! –
Tôi tự hỏi tại sao bạn tuôn ra và xóa phiên ** trước khi ** tăng chỉ số vòng lặp 'i'. Tôi đoán bạn nên thả 'i ++' từ 'for' loop và thay đổi nếu có điều kiện thành' ++ i% 50 == 0'. (Lỗi trong tài liệu Hibernate?) – DylanYi
@dylanyi Đó chỉ là một ví dụ. Có lẽ chỉ số i có liên quan đến quét một mảng nguồn (xem record.setXXX: nó lấy dữ liệu từ đâu?). Flushing lúc 0 trên đầu không tạo ra sự khác biệt như vậy khi bạn xử lý hàng triệu bản ghi –