2011-07-14 37 views
23

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 

Trả lời

75

Khi bạn gọi session.save(), hibernate sẽ tạo ra một SQL INSERT. SQL INSERT này sẽ được nối thêm vào DB trong quá trình xả (ví dụ: session.flush()).

Trong khi xả, nếu hibernate.jdbc.batch_size được đặt thành giá trị khác 0, Hibernate sẽ sử dụng tính năng tạo khối được giới thiệu trong JDBC2 API để phát hành đợt chèn SQL cho DB.

Ví dụ, nếu bạn save() 100 hồ sơ và hibernate.jdbc.batch_size của bạn được thiết lập để 50. Trong bốc hỏa, thay vì vấn đề SQL sau 100 lần:

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 sẽ nhóm chúng theo lô 50, và chỉ vấn đề 2 SQL để DB, như thế này:

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') 

Xin lưu ý rằng Hibernate sẽ vô hiệu hóa chèn trạm trộn ở cấp JDBC minh bạch nếu khóa chính của bảng chèn là GenerationType.Identity.

Từ nhật ký của bạn: bạn save() chỉ một bản ghi và sau đó flush(), do đó, chỉ có một INSERT SQL phụ thêm được xử lý cho mỗi lần xả. Đó là lý do tại sao Hibernate không thể giúp bạn chèn hàng loạt vì chỉ có một INSERT SQL được xử lý. Bạn nên save() tối đa số lượng bản ghi nhất định trước khi gọi số flush() thay vì gọi số flush() cho mỗi save().

Các thực hành tốt nhất của chèn hàng loạt là một cái gì đó như thế này:

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(); 

Bạn tiết kiệm và xối vào hồ sơ lô hàng bởi hàng loạt. Vào cuối mỗi lô, bạn nên xóa ngữ cảnh kiên trì để giải phóng một số bộ nhớ để ngăn chặn sự kiệt sức của bộ nhớ khi mọi đối tượng liên tục được đặt vào bộ đệm mức đầu tiên (bộ nhớ JVM của bạn). Bạn cũng có thể vô hiệu hóa bộ nhớ cache cấp thứ hai để giảm chi phí không cần thiết.


tham khảo:

+2

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! –

+2

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

+0

@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 –

3
11:02:56.133 [main] DEBUG o.h.transaction.JDBCTransaction - commit  

này được nói rằng cơ sở dữ liệu được cam kết sau mỗi lần chèn Đảm bảo bạn không cam kết giao dịch của bạn/đóng cửa phiên của bạn bên trong vòng lặp chèn làm điều này. một lần ở cuối thay thế.

+0

bạn nên, tuy nhiên, tuôn ra và xóa phiên của bạn mỗi vài 1.000 hồ sơ hoặc lâu hơn. – jtahlborn

+0

@jtahlborn có điểm rất tốt, nếu không Hibernate sẽ hết bộ nhớ – prunge

4

Nếu bạn phải sử dụng ngủ đông cho công việc hàng loạt lớn StatelessSession là con đường để đi. Nó sắp xếp mọi thứ xuống bản đồ các câu lệnh chuyển đổi-đối-SQL-cơ bản nhất và loại bỏ tất cả các chi phí của các tính năng ORM mà bạn không sử dụng khi chỉ nhồi nhét các hàng vào trong bán buôn DB.

Nó cũng sẽ dễ dàng hơn nhiều để đưa ra đề nghị trên mã thực tế của bạn hơn so với log :)

+0

Tôi biết điều đó sẽ xảy ra. Các mã thực sự là naca tạo ra java (từ COBOL) do đó, nó vô cùng khó khăn để gỡ lỗi và có được đầu của bạn xung quanh. Vẫn chưa tìm thấy nơi chèn là tiếng thở dài –