2011-07-14 12 views
23

Questo programma esegue decine di migliaia di inserimenti consecutivi uno dopo l'altro. Non ho mai usato Hibernate prima. Sto ottenendo prestazioni estremamente lente (se mi collego ed eseguo manualmente l'SQL sono 10-12x più veloce. Il mio batch_size è impostato su 50 come per molte esercitazioni di ibernazione.Hibernate batch confusion size

Ecco un registro da un singolo inserto - forse si potrebbe aiutarmi a capire esattamente cosa sta succedendo:.

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 

risposta

75

Quando si chiama session.save(), ibernazione genererà uno SQL INSERT. Questo INSERT SQL verrà aggiunto al DB durante lo scarico (ad esempio session.flush()).

Durante lo svuotamento, se hibernate.jdbc.batch_size è impostato su un valore diverso da zero, Hibernate utilizzerà la funzione di batch introdotta nell'API JDBC2 per immettere SQL dell'inserto batch nel DB.

Ad esempio, se si save() 100 record e la vostra hibernate.jdbc.batch_size è impostato su 50. Durante il lavaggio, invece di eseguire i seguenti SQL 100 volte:

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

in Hibernate sarà raggrupparli in lotti di 50, e solo numero 2 di SQL al DB, in questo modo:

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

prega di notare che Hibernate avrebbe disabilitare inserto dosaggio a livello JDBC in modo trasparente se la chiave primaria della tabella inserimento è GenerationType.Identity.

Dal registro: è save() un solo record e quindi flush(), quindi è possibile elaborare un solo INSERT SQL aggiuntivo per ogni colore. Ecco perché Hibernate non può aiutarti a inserire in batch poiché è necessario elaborare un solo SQL INSERT. È necessario save() fino alla quantità specifica di record prima di chiamare flush() anziché chiamare flush() per ogni save().

La migliore prassi di inserire lotto è qualcosa di simile:

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

Risparmi e lavare il batch record per lotto. Alla fine di ogni batch è necessario cancellare il contesto di persistenza per liberare memoria per evitare l'esaurimento della memoria poiché ogni oggetto persistente viene inserito nella cache di primo livello (la memoria della JVM). È inoltre possibile disabilitare la cache di secondo livello per ridurre l'overhead non necessario.


Riferimento:

+2

Risposta fantastica. Se potessi invitarvi di più, lo farei. Sono riuscito a risolverlo, ma grazie comunque! –

+2

Mi chiedo perché svuota e svuota la sessione ** prima ** incrementando l'indice di ciclo 'i'. Immagino che dovresti rilasciare 'i ++' dal ciclo 'for' e cambiare se condizionale a' ++ i% 50 == 0'. (Errore nella documentazione di Hibernate?) – DylanYi

+0

@dylanyi Questo è solo un esempio. Forse l'indice i è legato alla scansione di un array sorgente (vedi record.setXXX: da dove prende i dati?). Flushing a 0 all'inizio non fa la differenza quando si gestiscono milioni di record –

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

questo sta dicendo che il database sta commettendo dopo ogni inserto Assicurarsi che non sta commettendo la transazione/chiudendo la sessione all'interno del ciclo di inserimento fare questo. invece alla fine,

+0

si dovrebbe, tuttavia, a filo e svuotare la sessione di ogni pochi 1000 record o giù di lì. – jtahlborn

+0

@jtahlborn sì ottimo punto, altrimenti Hibernate esaurirà la memoria – prunge

4

Se è necessario utilizzare l'ibernazione per lavori batch enormi, StatelessSession è la strada da percorrere. Riduce le cose alla più semplice mappatura di converting-objects-to-SQL ed elimina tutto il sovraccarico delle funzionalità ORM che non state utilizzando quando si riempiono le righe nel DB all'ingrosso.

Sarebbe anche molto più facile da fare suggerimenti sul codice vero che il registro :)

+0

So che lo farebbe. Il codice in realtà è naca generato da java (da COBOL) quindi è incredibilmente difficile eseguire il debug e avere la testa. Ancora ancora da trovare dove l'inserto è sospiro –