I'm using Hibernate 2.1.2, with DB2.

I'm flushing a complex object graph, consisting entirely of new objects. It does all of the inserts, but then does several updates at the end that it seems should be unnecessary. The objects being updated later are inserted empty, then updated to include the data even though all the data was present in the object before the flush was called.

Is this normal behavior? I've read the bi-directional relationship documentation over and over, and it seems that if I have my inverse="true" settings incorrect it could cause this behavior on the child objects (an insert and an update) but my problem seems to be the parent objects. I can post all my mappings but as I said, it's fairly complex and would probably be too much to wade through.

Here's an exerpt from my log file:

2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Inserting entity: [com.mvsc.czee.business.claims.Incident#550]
2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Version: 2004-02-19 09:07:14.358
2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.SQL - insert into RM_INCIDENT (modified_ts, catastrophe_nbr, description_txt, loss_dt, loss_time, on_premises_ind, circumstance_cd, location_name, address1_txt, address2_txt, address3_txt, address4_txt, city_name, juris_id, state_cd, country_cd, county_txt, zip_cd, phone_nbr, location_nbr, phys_loc_cd, division_nbr, store_nbr, store_country_cd, created_ts, created_by_userid, modified_by_userid, incident_id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - preparing statement
2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Dehydrating entity: [com.mvsc.czee.business.claims.Incident#550]
2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '19 February 2004 09:07:14' to parameter: 1
2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.type.IntegerType - binding null to parameter: 2
2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 3
2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.type.DateType - binding null to parameter: 4
2004-02-19 09:07:34,157 [main] DEBUG net.sf.hibernate.type.TimeType - binding null to parameter: 5
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding 'U' to parameter: 6
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 7
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 8
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 9
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 10
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 11
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 12
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 13
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 14
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 15
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 16
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 17
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 18
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 19
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 20
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 21
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 22
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 23
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 24
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '19 February 2004 09:07:14' to parameter: 25
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding 'convert' to parameter: 26
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 27
2004-02-19 09:07:34,167 [main] DEBUG net.sf.hibernate.type.LongType - binding '550' to parameter: 28
2004-02-19 09:07:34,177 [main] DEBUG net.sf.hibernate.persister.NormalizedEntityPersister - Inserting entity: [com.mvsc.czee.business.claims.Claimant#718]
2004-02-19 09:07:34,177 [main] DEBUG net.sf.hibernate.persister.NormalizedEntityPersister - Version: 2004-02-19 09:07:14.418
2004-02-19 09:07:34,177 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
2004-02-19 09:07:34,177 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - closing statement
2004-02-19 09:07:34,177 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-02-19 09:07:34,177 [main] DEBUG net.sf.hibernate.SQL - insert into RM_CLAIMANT (modified_ts, address_txt, address2_txt, address3_txt, address4_txt, careOf_txt, city_name, mail_address_txt, mail_address2_txt, mail_address3_txt, mail_address4_txt, mail_careOf_txt, mail_city_name, birth_dt, death_dt, death_result_cd, ssn, id_txt, id_qualifier_cd, education_level_cd, email_txt, juris_id, state_cd, country_cd, mail_juris_id, mail_state_cd, mail_country_cd, zip_cd, mail_zip_cd, first_name, last_name, gender_cd, guardian_name, middle_name, marital_status_cd, last_nm_suffix_txt, name_prefix_cd, goes_by_name, phone1_ext_nbr, phone2_ext_nbr, phone3_ext_nbr, phone4_ext_nbr, phone1_nbr, phone2_nbr, phone3_nbr, phone4_nbr, phone1_type_cd, phone2_type_cd, phone3_type_cd, phone4_type_cd, primary_phone_id, prefer_lang_txt, emplr_2_name, emplr_2_phone_nbr, emplr_2_wage_amt, payee_bank_txt, payee_rtg_nbr_txt, payee_acct_nbr_txt, payee_acct_typ_txt, employee_ind, negligence_ind, negligence_pct, claimant_type_cd, created_ts, created_by_userid, modified_by_userid, incident_id, claimant_id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - preparing statement
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.persister.NormalizedEntityPersister - Dehydrating entity: [com.mvsc.czee.business.claims.Claimant#718]
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '19 February 2004 09:07:14' to parameter: 1
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 2
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 3
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 4
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 5
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 6
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 7
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 8
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 9
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 10
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 11
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 12
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 13
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.DateType - binding null to parameter: 14
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.DateType - binding null to parameter: 15
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.PersistentEnumType - binding '1' to parameter: 16
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 17
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 18
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 19
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 20
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 21
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 22
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 23
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 24
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 25
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 26
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 27
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 28
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 29
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 30
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 31
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.PersistentEnumType - binding null to parameter: 32
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 33
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 34
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 35
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 36
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.PersistentEnumType - binding null to parameter: 37
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 38
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 39
2004-02-19 09:07:34,187 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 40
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 41
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 42
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 43
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 44
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 45
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 46
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 47
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 48
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 49
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 50
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.IntegerType - binding null to parameter: 51
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 52
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 53
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 54
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.BigDecimalType - binding null to parameter: 55
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 56
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 57
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 58
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 59
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding 'U' to parameter: 60
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding 'U' to parameter: 61
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 62
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 63
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '19 February 2004 09:07:14' to parameter: 64
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding 'convert' to parameter: 65
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 66
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.LongType - binding '550' to parameter: 67
2004-02-19 09:07:34,197 [main] DEBUG net.sf.hibernate.type.LongType - binding '718' to parameter: 68
2004-02-19 09:07:34,217 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
2004-02-19 09:07:34,217 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - closing statement

<snip>


2004-02-19 09:07:35,839 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Updating entity: [com.mvsc.czee.business.claims.Incident#550]
2004-02-19 09:07:35,839 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Existing version: 2004-02-19 09:07:14.358 -> New version: 2004-02-19 09:07:33.976
2004-02-19 09:07:35,839 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-02-19 09:07:35,839 [main] DEBUG net.sf.hibernate.SQL - update RM_INCIDENT set modified_ts=?, catastrophe_nbr=?, description_txt=?, loss_dt=?, loss_time=?, on_premises_ind=?, circumstance_cd=?, location_name=?, address1_txt=?, address2_txt=?, address3_txt=?, address4_txt=?, city_name=?, juris_id=?, state_cd=?, country_cd=?, county_txt=?, zip_cd=?, phone_nbr=?, location_nbr=?, phys_loc_cd=?, division_nbr=?, store_nbr=?, store_country_cd=?, created_ts=?, created_by_userid=?, modified_by_userid=? where incident_id=? and modified_ts=?
2004-02-19 09:07:35,839 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - preparing statement
2004-02-19 09:07:35,839 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Dehydrating entity: [com.mvsc.czee.business.claims.Incident#550]
2004-02-19 09:07:35,839 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '19 February 2004 09:07:33' to parameter: 1
2004-02-19 09:07:35,839 [main] DEBUG net.sf.hibernate.type.IntegerType - binding '0' to parameter: 2
2004-02-19 09:07:35,839 [main] DEBUG net.sf.hibernate.type.StringType - binding 'CUSTOMER TRIPPED OVER MERCHANDISE' to parameter: 3
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.DateType - binding '04 April 2002' to parameter: 4
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.TimeType - binding '16:15:00' to parameter: 5
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding 'Y' to parameter: 6
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 7
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 8
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding '201 Waldon Rd' to parameter: 9
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 10
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 11
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 12
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding 'Harlan' to parameter: 13
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.LongType - binding '18' to parameter: 14
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding 'KY' to parameter: 15
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding 'US' to parameter: 16
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 17
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding '40831-0000' to parameter: 18
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding '606-573-2206' to parameter: 19
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding 'T020' to parameter: 20
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 21
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.LongType - binding '1' to parameter: 22
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.LongType - binding '1743' to parameter: 23
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding 'US' to parameter: 24
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '19 February 2004 09:07:14' to parameter: 25
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding 'convert' to parameter: 26
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.StringType - binding 'convert' to parameter: 27
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.LongType - binding '550' to parameter: 28
2004-02-19 09:07:35,849 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '19 February 2004 09:07:14' to parameter: 29
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - closing statement
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.persister.NormalizedEntityPersister - Updating entity: [com.mvsc.czee.business.claims.Claimant#718]
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.persister.NormalizedEntityPersister - Existing version: 2004-02-19 09:07:14.418 -> New version: 2004-02-19 09:07:33.986
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.SQL - update RM_CLAIMANT set modified_ts=?, address_txt=?, address2_txt=?, address3_txt=?, address4_txt=?, careOf_txt=?, city_name=?, mail_address_txt=?, mail_address2_txt=?, mail_address3_txt=?, mail_address4_txt=?, mail_careOf_txt=?, mail_city_name=?, birth_dt=?, death_dt=?, death_result_cd=?, ssn=?, id_txt=?, id_qualifier_cd=?, education_level_cd=?, email_txt=?, juris_id=?, state_cd=?, country_cd=?, mail_juris_id=?, mail_state_cd=?, mail_country_cd=?, zip_cd=?, mail_zip_cd=?, first_name=?, last_name=?, gender_cd=?, guardian_name=?, middle_name=?, marital_status_cd=?, last_nm_suffix_txt=?, name_prefix_cd=?, goes_by_name=?, phone1_ext_nbr=?, phone2_ext_nbr=?, phone3_ext_nbr=?, phone4_ext_nbr=?, phone1_nbr=?, phone2_nbr=?, phone3_nbr=?, phone4_nbr=?, phone1_type_cd=?, phone2_type_cd=?, phone3_type_cd=?, phone4_type_cd=?, primary_phone_id=?, prefer_lang_txt=?, emplr_2_name=?, emplr_2_phone_nbr=?, emplr_2_wage_amt=?, payee_bank_txt=?, payee_rtg_nbr_txt=?, payee_acct_nbr_txt=?, payee_acct_typ_txt=?, employee_ind=?, negligence_ind=?, negligence_pct=?, claimant_type_cd=?, created_ts=?, created_by_userid=?, modified_by_userid=?, incident_id=? where claimant_id=? and modified_ts=?
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - preparing statement
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.persister.NormalizedEntityPersister - Dehydrating entity: [com.mvsc.czee.business.claims.Claimant#718]
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '19 February 2004 09:07:33' to parameter: 1
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 2
2004-02-19 09:07:35,859 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 3
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 4
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 5
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 6
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 7
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 8
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 9
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 10
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 11
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 12
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 13
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.DateType - binding '28 April 1938' to parameter: 14
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.DateType - binding null to parameter: 15
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.PersistentEnumType - binding '1' to parameter: 16
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 17
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding '' to parameter: 18
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 19
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 20
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 21
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 22
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding '' to parameter: 23
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding '' to parameter: 24
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 25
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 26
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 27
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 28
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 29
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding 'Imogene' to parameter: 30
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding 'Burton' to parameter: 31
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.PersistentEnumType - binding '0' to parameter: 32
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 33
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding '' to parameter: 34
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 35
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 36
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.PersistentEnumType - binding null to parameter: 37
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 38
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 39
2004-02-19 09:07:35,869 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 40
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 41
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 42
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 43
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 44
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 45
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 46
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 47
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 48
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 49
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 50
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.IntegerType - binding null to parameter: 51
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 52
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 53
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 54
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.BigDecimalType - binding null to parameter: 55
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 56
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 57
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 58
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 59
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding 'U' to parameter: 60
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding 'U' to parameter: 61
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.LongType - binding '0' to parameter: 62
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.LongType - binding null to parameter: 63
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '19 February 2004 09:07:14' to parameter: 64
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding 'convert' to parameter: 65
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.StringType - binding 'convert' to parameter: 66
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.LongType - binding '550' to parameter: 67
2004-02-19 09:07:35,879 [main] DEBUG net.sf.hibernate.type.LongType - binding '718' to parameter: 68
2004-02-19 09:07:35,889 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '19 February 2004 09:07:14' to parameter: 69
2004-02-19 09:07:35,929 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
2004-02-19 09:07:35,929 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - closing statement


What could cause this odd behavior? I wouldn't care, except it also seems to be requiring a higher lock for the update and is causing contention.

Thanks for your help!!

Jenica Humphreys
MountainView Software

Adding a child to a parent will increase the evrsion (or timestamp) of the parent and provoke an update.

This is most likely caused by incorect inverse settings. Have you read both http://www.hibernate.org/hib_docs/reference/html/parent-child.html and http://www.hibernate.org/155.html?

Hi Emmanuel,

That makes sense, but it seems like if this is the first time the object has been flushed it shouldn't need both an insert and an update - no matter how many times the version may have changed! Am I incorrect on that?

Jenica

It's an (arguable) implementation choice

Are you *certain* that this is 2.1.2? There was a bug in 2.1 and 2.1.1 which caused this behavior. I thought it was fixed now...

P.S. You snipped the important part of the log, where I could see *why* the update occurred...

We're downloading 2.1.2 again to make /certain/ that we don't have old source code, but I'm pretty sure.

Here's everything it does before it starts inserting:

2004-02-19 09:07:32,014 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
2004-02-19 09:07:32,014 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.claims.Incident
2004-02-19 09:07:32,014 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.claims.Incident.notes
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,024 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@3ca56f
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,024 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@11394e
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_id' for update
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,024 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@11394e ... newId = 29966
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,024 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@3ca56f
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29965
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.IncidentNote#29965]
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,024 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.024
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Note.subnotes
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,034 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@6bbb36
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,034 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@5006a7
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'subnote_id' for update
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,034 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@5006a7 ... newId = 29966
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,034 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@6bbb36
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,034 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29965
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.Subnote#29965]
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.044
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Subnote.fragments
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,044 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@c42b5
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,044 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@6f9d00
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_fragment_id' for update
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,044 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@6f9d00 ... newId = 27126
2004-02-19 09:07:32,044 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,054 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@c42b5
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 27125
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.NoteFragment#27125]
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.054
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,054 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@6dd93
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,054 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@3d0fea
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_id' for update
2004-02-19 09:07:32,054 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,064 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@3d0fea ... newId = 29967
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,064 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@6dd93
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29966
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.IncidentNote#29966]
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.064
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Note.subnotes
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,064 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@76ae4d
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,064 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@2d4c7e
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'subnote_id' for update
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,064 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@2d4c7e ... newId = 29967
2004-02-19 09:07:32,064 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,074 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@76ae4d
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29966
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.Subnote#29966]
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.074
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Subnote.fragments
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,074 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@590254
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,074 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@280c85
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_fragment_id' for update
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,074 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@280c85 ... newId = 27127
2004-02-19 09:07:32,074 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,084 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@590254
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,084 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
2004-02-19 09:07:32,084 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
2004-02-19 09:07:32,084 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
2004-02-19 09:07:32,084 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
2004-02-19 09:07:32,084 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
2004-02-19 09:07:32,084 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
2004-02-19 09:07:32,084 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
2004-02-19 09:07:32,084 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 27126
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.NoteFragment#27126]
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.084
2004-02-19 09:07:32,084 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,094 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@42e163
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,094 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@5b4b49
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_id' for update
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,094 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@5b4b49 ... newId = 29968
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,094 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@42e163
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29967
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.IncidentNote#29967]
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.094
2004-02-19 09:07:32,094 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Note.subnotes
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,104 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@1238ad
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,104 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@471c00
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'subnote_id' for update
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,104 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@471c00 ... newId = 29968
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,104 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@1238ad
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29967
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.Subnote#29967]
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.104
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,104 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Subnote.fragments
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,114 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@766ec3
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,114 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@61fcdd
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_fragment_id' for update
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,114 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@61fcdd ... newId = 27128
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,114 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@766ec3
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 27127
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.NoteFragment#27127]
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.114
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,114 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,124 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@2b3cda
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,124 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@283826
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_id' for update
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,124 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@283826 ... newId = 29969
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,124 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@2b3cda
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29968
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.IncidentNote#29968]
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.124
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Note.subnotes
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,124 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,134 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@1a68ee
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,134 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@5ef79f
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'subnote_id' for update
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,134 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@5ef79f ... newId = 29969
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,134 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@1a68ee
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29968
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.Subnote#29968]
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.134
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Subnote.fragments
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,134 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,144 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@773a14
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,144 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@60315
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_fragment_id' for update
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,144 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@60315 ... newId = 27129
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,144 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@773a14
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 27128
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.NoteFragment#27128]
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.144
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,144 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,154 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@1cc2a8
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,154 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@2fae6c
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_id' for update
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,154 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@2fae6c ... newId = 29970
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,154 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@1cc2a8
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29969
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.IncidentNote#29969]
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.154
2004-02-19 09:07:32,154 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Note.subnotes
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,164 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@35be06
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,164 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@4eb471
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'subnote_id' for update
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,164 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@4eb471 ... newId = 29970
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,164 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@35be06
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29969
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.Subnote#29969]
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.164
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Subnote.fragments
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,164 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,174 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@4a8f43
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,174 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@3b18f
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_fragment_id' for update
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,174 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@3b18f ... newId = 27130
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,174 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@4a8f43
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 27129
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.NoteFragment#27129]
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.174
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,174 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,184 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@133926
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,184 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@cf70f
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_id' for update
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,184 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@cf70f ... newId = 29971
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,184 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@133926
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29970
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.IncidentNote#29970]
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.184
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Note.subnotes
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,184 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,194 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@353f6
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,194 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@7d6f07
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'subnote_id' for update
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,194 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@7d6f07 ... newId = 29971
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,194 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@353f6
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 29970
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.Subnote#29970]
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.194
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: com.mvsc.czee.business.note.Subnote.fragments
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,194 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - total checked-out connections: 1
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - using pooled JDBC connection, pool size: 0
2004-02-19 09:07:32,204 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created hibernate session ... net.sf.hibernate.impl.SessionImpl@82dfc
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - begin
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - current autocommit status:false
2004-02-19 09:07:32,204 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Created transaction ... net.sf.hibernate.transaction.JDBCTransaction@2fba9
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.SQL - select next_id from RM_Control where key_column_txt = 'note_fragment_id' for update
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.SQL - update RM_Control set next_id = ? where key_column_txt = ?
2004-02-19 09:07:32,204 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Committing transaction ... net.sf.hibernate.transaction.JDBCTransaction@2fba9 ... newId = 27131
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.transaction.JDBCTransaction - commit
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,204 [main] DEBUG com.mvsc.czee.persistence.CzeeIdGenerator - Closing hibernate session ... net.sf.hibernate.impl.SessionImpl@82dfc
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.connection.DriverManagerConnectionProvider - returning connection to pool, pool size: 1
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.impl.SessionImpl - generated identifier: 27130
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [com.mvsc.czee.business.note.NoteFragment#27130]
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.impl.SessionImpl - calling onSave()
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-02-19 09:07:32.204
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.NoteFragment
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.Subnote
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: com.mvsc.czee.business.note.IncidentNote
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-02-19 09:07:32,204 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() unsaved instance
2004-02-19 09:07:32,204 [main] DEBUG ne

I don't understand this log. It shows a bunch of different sessions being opened and closed...

The sessions being opened and closed are due to a new id generator that we wrote. It gets its own session and gets a "next id" out of a table in the database, using direct sql.

Jenica

Incidentally, we wrote our own id generator partially to avoid using identities because the identity causes special handling in hibernate, inserting the record as soon as it is associated with the session in order to get the identity value.

At least, that was what we were thinking. :)

Jenica

I dunno ... I can't make sense of the log. Its way too complicated. I'm a bit suspicious of your id generation strategy also. Why not try using "increment", for a test, and see what happens...

I did change it to increment, but am seeing the same behavior.

I think after all of this I've figured out the answer to my own problem. I suspect that the problem is I am associating the objects to the session initially when they're empty, then adding data to them.

It seems that the object is inserted however it was locked into the session initially, then updated to the current state. So, if I wait to call saveOrUpdate until I'm finished populating the object I wouldn't see the insert and update.

I can't wait because I need the generated id... :) Back to the drawing board!

Thanks for your help -
Jenica

Ok... We changed the hibernate source in SessionImpl.FlushEntity to check if an object to be updated is already scheduled for insert. If it is, we remove it from the list of insertions and re-add it as an insertion with all of the new data, rather than scheduling an update.

What are the ramifications of this change?

Why doesn't hibernate do this by default?

Thanks for your help!
Jenica Humphreys