And this is the working case log, for the same situation, with the flush inside and in the more readable form as above:
[code]
15:51:30,478 INFO [SpringHibernatePartyService] updating customer it.esselunga.ecommerce.data.model.Customer@125d568[partyId=58195] with relatives map {it.esselunga.ecommerce.data.model.Person@1cfa965[partyId=<null>]=2213}
15:51:30,478 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate.SessionHolder@2ee7e5] for key [net.sf.hibernate.impl.SessionFactoryImpl@69695f] bound to thread [main]
15:51:30,478 DEBUG [SessionImpl] find: select relationship.relatedParty from Person p join p.relatedPartiesFrom relationship where p.id=? and relationship.relationshipType.class=it.esselunga.ecommerce.data.model.RelativeType
15:51:30,478 DEBUG [QueryParameters] parameters: [58195]
15:51:30,478 DEBUG [SessionImpl] flushing session
15:51:30,478 DEBUG [SessionImpl] Flushing entities and processing referenced collections
15:51:30,478 DEBUG [SessionImpl] Processing unreferenced collections
15:51:30,478 DEBUG [SessionImpl] Scheduling collection removes/(re)creates/updates
15:51:30,478 DEBUG [SessionImpl] Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
15:51:30,478 DEBUG [SessionImpl] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
15:51:30,478 DEBUG [SessionImpl] Dont need to execute flush
15:51:30,478 DEBUG [QueryTranslator] HQL: select relationship.relatedParty from it.esselunga.ecommerce.data.model.Person p join p.relatedPartiesFrom relationship where p.id=? and relationship.relationshipType.class=it.esselunga.ecommerce.data.model.RelativeType
15:51:30,478 DEBUG [QueryTranslator] SQL: select party3_.PARTY_ID as PARTY_ID, decode (party3_.PARTY_ID, party3__2_.PARTY_ID, 1, party3__1_.PARTY_ID, 2, party3__3_.PARTY_ID, 3,0 ) as clazz_, party3_.PARTY_TYPE as PARTY_TYPE8_, party3__1_.TITLE as TITLE10_, party3__1_.SURNAME as SURNAME10_, party3__1_.FORENAME as FORENAME10_, party3__1_.EMAIL as EMAIL10_, party3__1_.HOME_TEL as HOME_TEL10_, party3__1_.WORK_TEL as WORK_TEL10_, party3__1_.MOBILE_TEL as MOBILE_TEL10_, party3__1_.DATE_OF_BIRTH as DATE_OF_9_10_, party3__1_.SEX as SEX10_, party3__1_.DETAILS_PRIVATE as DETAILS11_10_, party3__1_.CREATION_DATE as CREATIO12_10_, party3__1_.PROFESSION_ID as PROFESS13_10_, party3__1_.EDUCATION_LEVEL_ID as EDUCATI14_10_, party3__2_.FIDELITY_CARD_TYPE as FIDELITY2_11_, party3__2_.FIDELITY_CARD_NUMBER as FIDELITY3_11_, party3__2_.IS_NEW_CARD_NUMBER as IS_NEW_C4_11_, party3__2_.HOW_MANY_RELATIVES as HOW_MANY5_11_, party3__2_.SEND_INFO as SEND_INFO11_, party3__3_.GROUP_NAME as GROUP_NAME12_, party3__3_.DESCRIPTION as DESCRIPT3_12_ from PERSON person0_, PARTY person0__1_, PARTY_RELATIONSHIP relatedpar1_, ENUMERATION partyrelat2_, PARTY party3_, PERSON party3__1_, CUSTOMER party3__2_, PARTY_GROUP party3__3_ where person0_.PARTY_ID=person0__1_.PARTY_ID and person0_.PARTY_ID=relatedpar1_.PARTY_ID_TO and relatedpar1_.PARTY_ID_FROM=party3_.PARTY_ID and party3_.PARTY_ID=party3__1_.PARTY_ID(+) and party3_.PARTY_ID=party3__2_.PARTY_ID(+) and party3_.PARTY_ID=party3__3_.PARTY_ID(+) and ((person0_.PARTY_ID=? )and(partyrelat2_.ENUM_TYPE='RelativeType' and relatedpar1_.RELATIONSHIP_TYPE_ID=partyrelat2_.ENUM_ID))
15:51:30,488 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:30,488 DEBUG [SQL] select party3_.PARTY_ID as PARTY_ID, decode (party3_.PARTY_ID, party3__2_.PARTY_ID, 1, party3__1_.PARTY_ID, 2, party3__3_.PARTY_ID, 3,0 ) as clazz_, party3_.PARTY_TYPE as PARTY_TYPE8_, party3__1_.TITLE as TITLE10_, party3__1_.SURNAME as SURNAME10_, party3__1_.FORENAME as FORENAME10_, party3__1_.EMAIL as EMAIL10_, party3__1_.HOME_TEL as HOME_TEL10_, party3__1_.WORK_TEL as WORK_TEL10_, party3__1_.MOBILE_TEL as MOBILE_TEL10_, party3__1_.DATE_OF_BIRTH as DATE_OF_9_10_, party3__1_.SEX as SEX10_, party3__1_.DETAILS_PRIVATE as DETAILS11_10_, party3__1_.CREATION_DATE as CREATIO12_10_, party3__1_.PROFESSION_ID as PROFESS13_10_, party3__1_.EDUCATION_LEVEL_ID as EDUCATI14_10_, party3__2_.FIDELITY_CARD_TYPE as FIDELITY2_11_, party3__2_.FIDELITY_CARD_NUMBER as FIDELITY3_11_, party3__2_.IS_NEW_CARD_NUMBER as IS_NEW_C4_11_, party3__2_.HOW_MANY_RELATIVES as HOW_MANY5_11_, party3__2_.SEND_INFO as SEND_INFO11_, party3__3_.GROUP_NAME as GROUP_NAME12_, party3__3_.DESCRIPTION as DESCRIPT3_12_ from PERSON person0_, PARTY person0__1_, PARTY_RELATIONSHIP relatedpar1_, ENUMERATION partyrelat2_, PARTY party3_, PERSON party3__1_, CUSTOMER party3__2_, PARTY_GROUP party3__3_ where person0_.PARTY_ID=person0__1_.PARTY_ID and person0_.PARTY_ID=relatedpar1_.PARTY_ID_TO and relatedpar1_.PARTY_ID_FROM=party3_.PARTY_ID and party3_.PARTY_ID=party3__1_.PARTY_ID(+) and party3_.PARTY_ID=party3__2_.PARTY_ID(+) and party3_.PARTY_ID=party3__3_.PARTY_ID(+) and ((person0_.PARTY_ID=? )and(partyrelat2_.ENUM_TYPE='RelativeType' and relatedpar1_.RELATIONSHIP_TYPE_ID=partyrelat2_.ENUM_ID))
Hibernate: select party3_.PARTY_ID as PARTY_ID, decode (party3_.PARTY_ID, party3__2_.PARTY_ID, 1, party3__1_.PARTY_ID, 2, party3__3_.PARTY_ID, 3,0 ) as clazz_, party3_.PARTY_TYPE as PARTY_TYPE8_, party3__1_.TITLE as TITLE10_, party3__1_.SURNAME as SURNAME10_, party3__1_.FORENAME as FORENAME10_, party3__1_.EMAIL as EMAIL10_, party3__1_.HOME_TEL as HOME_TEL10_, party3__1_.WORK_TEL as WORK_TEL10_, party3__1_.MOBILE_TEL as MOBILE_TEL10_, party3__1_.DATE_OF_BIRTH as DATE_OF_9_10_, party3__1_.SEX as SEX10_, party3__1_.DETAILS_PRIVATE as DETAILS11_10_, party3__1_.CREATION_DATE as CREATIO12_10_, party3__1_.PROFESSION_ID as PROFESS13_10_, party3__1_.EDUCATION_LEVEL_ID as EDUCATI14_10_, party3__2_.FIDELITY_CARD_TYPE as FIDELITY2_11_, party3__2_.FIDELITY_CARD_NUMBER as FIDELITY3_11_, party3__2_.IS_NEW_CARD_NUMBER as IS_NEW_C4_11_, party3__2_.HOW_MANY_RELATIVES as HOW_MANY5_11_, party3__2_.SEND_INFO as SEND_INFO11_, party3__3_.GROUP_NAME as GROUP_NAME12_, party3__3_.DESCRIPTION as DESCRIPT3_12_ from PERSON person0_, PARTY person0__1_, PARTY_RELATIONSHIP relatedpar1_, ENUMERATION partyrelat2_, PARTY party3_, PERSON party3__1_, CUSTOMER party3__2_, PARTY_GROUP party3__3_ where person0_.PARTY_ID=person0__1_.PARTY_ID and person0_.PARTY_ID=relatedpar1_.PARTY_ID_TO and relatedpar1_.PARTY_ID_FROM=party3_.PARTY_ID and party3_.PARTY_ID=party3__1_.PARTY_ID(+) and party3_.PARTY_ID=party3__2_.PARTY_ID(+) and party3_.PARTY_ID=party3__3_.PARTY_ID(+) and ((person0_.PARTY_ID=? )and(partyrelat2_.ENUM_TYPE='RelativeType' and relatedpar1_.RELATIONSHIP_TYPE_ID=partyrelat2_.ENUM_ID))
15:51:30,498 DEBUG [BatcherImpl] preparing statement
15:51:30,498 DEBUG [IntegerType] binding '58195' to parameter: 1
15:51:30,498 DEBUG [IntegerType] binding '58195' to parameter: 1
15:51:30,528 DEBUG [Loader] processing result set
15:51:30,528 DEBUG [IntegerType] returning '58197' as column: PARTY_ID
15:51:30,528 DEBUG [IntegerType] returning '58197' as column: PARTY_ID
15:51:30,528 DEBUG [Loader] result row: 58197
15:51:30,528 DEBUG [IntegerType] returning '2' as column: clazz_
15:51:30,528 DEBUG [IntegerType] returning '2' as column: clazz_
15:51:30,528 DEBUG [Loader] Initializing object from ResultSet: 58197
15:51:30,528 DEBUG [Loader] Hydrating entity: it.esselunga.ecommerce.data.model.Person#58197
15:51:30,528 DEBUG [StringType] returning 'Mr.' as column: TITLE10_
15:51:30,528 DEBUG [StringType] returning 'Mr.' as column: TITLE10_
15:51:30,528 DEBUG [StringType] returning 'parente1' as column: SURNAME10_
15:51:30,528 DEBUG [StringType] returning 'parente1' as column: SURNAME10_
15:51:30,528 DEBUG [StringType] returning 'cognome1' as column: FORENAME10_
15:51:30,528 DEBUG [StringType] returning 'cognome1' as column: FORENAME10_
15:51:30,528 DEBUG [StringType] returning
'email-parente1@updatecustomer.it' as column: EMAIL10_
15:51:30,528 DEBUG [StringType] returning
'email-parente1@updatecustomer.it' as column: EMAIL10_
15:51:30,538 DEBUG [StringType] returning '02-57402284' as column: HOME_TEL10_
15:51:30,538 DEBUG [StringType] returning '02-57402284' as column: HOME_TEL10_
15:51:30,538 DEBUG [StringType] returning '347-0077078' as column: WORK_TEL10_
15:51:30,538 DEBUG [StringType] returning '347-0077078' as column: WORK_TEL10_
15:51:30,538 DEBUG [StringType] returning '347-0077078' as column: MOBILE_TEL10_
15:51:30,538 DEBUG [StringType] returning '347-0077078' as column: MOBILE_TEL10_
15:51:30,538 DEBUG [TimestampType] returning '11 novembre 1976 15:50:35' as column: DATE_OF_9_10_
15:51:30,538 DEBUG [TimestampType] returning '11 novembre 1976 15:50:35' as column: DATE_OF_9_10_
15:51:30,538 DEBUG [StringType] returning 'M' as column: SEX10_
15:51:30,538 DEBUG [StringType] returning 'M' as column: SEX10_
15:51:30,538 DEBUG [BooleanType] returning 'true' as column: DETAILS11_10_
15:51:30,538 DEBUG [BooleanType] returning 'true' as column: DETAILS11_10_
15:51:30,538 DEBUG [TimestampType] returning '07 maggio 2004 15:50:35' as column: CREATIO12_10_
15:51:30,538 DEBUG [TimestampType] returning '07 maggio 2004 15:50:35' as column: CREATIO12_10_
15:51:30,538 DEBUG [IntegerType] returning '2214' as column: PROFESS13_10_
15:51:30,538 DEBUG [IntegerType] returning '2214' as column: PROFESS13_10_
15:51:30,538 DEBUG [IntegerType] returning '2215' as column: EDUCATI14_10_
15:51:30,538 DEBUG [IntegerType] returning '2215' as column: EDUCATI14_10_
15:51:30,538 DEBUG [PersistentEnumType] returning '2' as column: PARTY_TYPE8_
15:51:30,538 DEBUG [PersistentEnumType] returning '2' as column: PARTY_TYPE8_
15:51:30,548 DEBUG [Loader] done processing result set (1 rows)
15:51:30,548 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:30,548 DEBUG [BatcherImpl] closing statement
15:51:30,548 DEBUG [Loader] total objects hydrated: 1
15:51:30,548 DEBUG [SessionImpl] resolving associations for [it.esselunga.ecommerce.data.model.Person#58197]
15:51:30,548 DEBUG [SessionImpl] creating collection wrapper:[it.esselunga.ecommerce.data.model.Person.userLogins#58197]
15:51:30,548 DEBUG [SessionImpl] creating collection wrapper:[it.esselunga.ecommerce.data.model.Person.trolleys#58197]
15:51:30,548 DEBUG [SessionImpl] creating collection wrapper:[it.esselunga.ecommerce.data.model.Person.shoppingLists#58197]
15:51:30,558 DEBUG [SessionImpl] creating collection wrapper:[it.esselunga.ecommerce.data.model.Person.addresses#58197]
15:51:30,558 DEBUG [SessionImpl] loading [it.esselunga.ecommerce.data.model.Profession#2214]
15:51:30,558 DEBUG [SessionImpl] attempting to resolve [it.esselunga.ecommerce.data.model.Profession#2214]
15:51:30,558 DEBUG [SessionImpl] object not resolved in any cache [it.esselunga.ecommerce.data.model.Profession#2214]
15:51:30,558 DEBUG [EntityPersister] Materializing entity: [it.esselunga.ecommerce.data.model.Profession#2214]
15:51:30,558 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:30,558 DEBUG [SQL] select profession0_.ENUM_ID as ENUM_ID0_, profession0_.ENUM_CODE as ENUM_CODE0_, profession0_.SEQUENCE as SEQUENCE0_, profession0_.DESCRIPTION as DESCRIPT5_0_ from ENUMERATION profession0_ where profession0_.ENUM_ID=?
Hibernate: select profession0_.ENUM_ID as ENUM_ID0_, profession0_.ENUM_CODE as ENUM_CODE0_, profession0_.SEQUENCE as SEQUENCE0_, profession0_.DESCRIPTION as DESCRIPT5_0_ from ENUMERATION profession0_ where profession0_.ENUM_ID=?
15:51:30,558 DEBUG [BatcherImpl] preparing statement
15:51:30,558 DEBUG [IntegerType] binding '2214' to parameter: 1
15:51:30,558 DEBUG [IntegerType] binding '2214' to parameter: 1
15:51:30,648 DEBUG [Loader] processing result set
15:51:30,648 DEBUG [Loader] result row: 2214
15:51:30,648 DEBUG [Loader] Initializing object from ResultSet: 2214
15:51:30,648 DEBUG [Loader] Hydrating entity: it.esselunga.ecommerce.data.model.Profession#2214
15:51:30,648 DEBUG [StringType] returning 'ingegnere' as column: ENUM_CODE0_
15:51:30,648 DEBUG [StringType] returning 'ingegnere' as column: ENUM_CODE0_
15:51:30,648 DEBUG [IntegerType] returning '1' as column: SEQUENCE0_
15:51:30,648 DEBUG [IntegerType] returning '1' as column: SEQUENCE0_
15:51:30,648 DEBUG [StringType] returning 'il mestiere piu antico del mondo' as column: DESCRIPT5_0_
15:51:30,648 DEBUG [StringType] returning 'il mestiere piu antico del mondo' as column: DESCRIPT5_0_
15:51:30,658 DEBUG [Loader] done processing result set (1 rows)
15:51:30,658 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:30,658 DEBUG [BatcherImpl] closing statement
15:51:30,668 DEBUG [Loader] total objects hydrated: 1
15:51:30,668 DEBUG [SessionImpl] resolving associations for [it.esselunga.ecommerce.data.model.Profession#2214]
15:51:30,668 DEBUG [SessionImpl] done materializing entity [it.esselunga.ecommerce.data.model.Profession#2214]
15:51:30,668 DEBUG [SessionImpl] loading [it.esselunga.ecommerce.data.model.EducationLevel#2215]
15:51:30,668 DEBUG [SessionImpl] attempting to resolve [it.esselunga.ecommerce.data.model.EducationLevel#2215]
15:51:30,668 DEBUG [SessionImpl] object not resolved in any cache [it.esselunga.ecommerce.data.model.EducationLevel#2215]
15:51:30,668 DEBUG [EntityPersister] Materializing entity: [it.esselunga.ecommerce.data.model.EducationLevel#2215]
15:51:30,668 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:30,668 DEBUG [SQL] select educationl0_.ENUM_ID as ENUM_ID0_, educationl0_.ENUM_CODE as ENUM_CODE0_, educationl0_.SEQUENCE as SEQUENCE0_, educationl0_.DESCRIPTION as DESCRIPT5_0_ from ENUMERATION educationl0_ where educationl0_.ENUM_ID=?
Hibernate: select educationl0_.ENUM_ID as ENUM_ID0_, educationl0_.ENUM_CODE as ENUM_CODE0_, educationl0_.SEQUENCE as SEQUENCE0_, educationl0_.DESCRIPTION as DESCRIPT5_0_ from ENUMERATION educationl0_ where educationl0_.ENUM_ID=?
15:51:30,668 DEBUG [BatcherImpl] preparing statement
15:51:30,668 DEBUG [IntegerType] binding '2215' to parameter: 1
15:51:30,668 DEBUG [IntegerType] binding '2215' to parameter: 1
15:51:30,688 DEBUG [Loader] processing result set
15:51:30,688 DEBUG [Loader] result row: 2215
15:51:30,688 DEBUG [Loader] Initializing object from ResultSet: 2215
15:51:30,688 DEBUG [Loader] Hydrating entity: it.esselunga.ecommerce.data.model.EducationLevel#2215
15:51:30,688 DEBUG [StringType] returning 'laurea' as column: ENUM_CODE0_
15:51:30,688 DEBUG [StringType] returning 'laurea' as column: ENUM_CODE0_
15:51:30,698 DEBUG [IntegerType] returning '1' as column: SEQUENCE0_
15:51:30,698 DEBUG [IntegerType] returning '1' as column: SEQUENCE0_
15:51:30,698 DEBUG [StringType] returning 'il livello di educazione della laurea' as column: DESCRIPT5_0_
15:51:30,698 DEBUG [StringType] returning 'il livello di educazione della laurea' as column: DESCRIPT5_0_
15:51:30,698 DEBUG [Loader] done processing result set (1 rows)
15:51:30,698 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:30,698 DEBUG [BatcherImpl] closing statement
15:51:30,698 DEBUG [Loader] total objects hydrated: 1
15:51:30,698 DEBUG [SessionImpl] resolving associations for [it.esselunga.ecommerce.data.model.EducationLevel#2215]
15:51:30,698 DEBUG [SessionImpl] done materializing entity [it.esselunga.ecommerce.data.model.EducationLevel#2215]
15:51:30,708 DEBUG [SessionImpl] creating collection wrapper:[it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58197]
15:51:30,708 DEBUG [SessionImpl] creating collection wrapper:[it.esselunga.ecommerce.data.model.Party.relatedPartiesTo#58197]
15:51:30,708 DEBUG [SessionImpl] done materializing entity [it.esselunga.ecommerce.data.model.Person#58197]
15:51:30,708 DEBUG [SessionImpl] initializing non-lazy collections
15:51:30,708 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate.SessionHolder@2ee7e5] for key [net.sf.hibernate.impl.SessionFactoryImpl@69695f] bound to thread [main]
15:51:30,708 DEBUG [Cascades] id unsaved-value strategy NULL
15:51:30,708 DEBUG [SessionImpl] reassociating transient instance: [it.esselunga.ecommerce.data.model.Customer#58195]
15:51:30,708 DEBUG [Cascades] processing cascades for: it.esselunga.ecommerce.data.model.Customer
15:51:30,708 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Customer.deliveryAddresses
15:51:30,708 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.userLogins
15:51:30,708 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.shoppingLists
15:51:30,708 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.addresses
15:51:30,708 DEBUG [Cascades] done processing cascades for: it.esselunga.ecommerce.data.model.Customer
15:51:30,708 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate.SessionHolder@2ee7e5] for key [net.sf.hibernate.impl.SessionFactoryImpl@69695f] bound to thread [main]
15:51:30,708 DEBUG [SessionImpl] loading [it.esselunga.ecommerce.data.model.Party#58195]
15:51:30,708 DEBUG [SessionImpl] attempting to resolve [it.esselunga.ecommerce.data.model.Party#58195]
15:51:30,708 DEBUG [SessionImpl] resolved object in session cache [it.esselunga.ecommerce.data.model.Party#58195]
15:51:30,708 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate.SessionHolder@2ee7e5] for key [net.sf.hibernate.impl.SessionFactoryImpl@69695f] bound to thread [main]
15:51:30,708 DEBUG [SessionImpl] deleting a persistent instance
15:51:30,708 DEBUG [SessionImpl] deleting [it.esselunga.ecommerce.data.model.Person#58197]
15:51:30,708 DEBUG [Cascades] processing cascades for: it.esselunga.ecommerce.data.model.Person
15:51:30,718 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.userLogins
15:51:30,718 DEBUG [SessionImpl] initializing collection [it.esselunga.ecommerce.data.model.Person.userLogins#58197]
15:51:30,718 DEBUG [SessionImpl] checking second-level cache
15:51:30,718 DEBUG [SessionImpl] collection not cached
15:51:30,718 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:30,718 DEBUG [SQL] select userlogins0_.USER_LOGIN_ID as USER_LOG1___, userlogins0_.PARTY_ID as PARTY_ID__, userlogins0_.USER_LOGIN_ID as USER_LOG1_0_, userlogins0_.USERNAME as USERNAME0_, userlogins0_.PASSWD as PASSWD0_, userlogins0_.DELETED as DELETED0_, userlogins0_.CREATION_DATE as CREATION5_0_, userlogins0_.CHANNEL_ID as CHANNEL_ID0_, userlogins0_.PARTY_ID as PARTY_ID0_ from USER_LOGIN userlogins0_ where userlogins0_.PARTY_ID=?
Hibernate: select userlogins0_.USER_LOGIN_ID as USER_LOG1___, userlogins0_.PARTY_ID as PARTY_ID__, userlogins0_.USER_LOGIN_ID as USER_LOG1_0_, userlogins0_.USERNAME as USERNAME0_, userlogins0_.PASSWD as PASSWD0_, userlogins0_.DELETED as DELETED0_, userlogins0_.CREATION_DATE as CREATION5_0_, userlogins0_.CHANNEL_ID as CHANNEL_ID0_, userlogins0_.PARTY_ID as PARTY_ID0_ from USER_LOGIN userlogins0_ where userlogins0_.PARTY_ID=?
15:51:30,718 DEBUG [BatcherImpl] preparing statement
15:51:30,718 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:30,718 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:30,749 DEBUG [Loader] result set contains (possibly empty) collection: [it.esselunga.ecommerce.data.model.Person.userLogins#58197]
15:51:30,749 DEBUG [SessionImpl] uninitialized collection: initializing
15:51:30,749 DEBUG [Loader] processing result set
15:51:30,749 DEBUG [Loader] done processing result set (0 rows)
15:51:30,749 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:30,749 DEBUG [BatcherImpl] closing statement
15:51:30,759 DEBUG [Loader] total objects hydrated: 0
15:51:30,759 DEBUG [SessionImpl] 1 collections were found in result set
15:51:30,759 DEBUG [SessionImpl] collection fully initialized: [it.esselunga.ecommerce.data.model.Person.userLogins#58197]
15:51:30,759 DEBUG [SessionImpl] 1 collections initialized
15:51:30,759 DEBUG [SessionImpl] initializing non-lazy collections
15:51:30,759 DEBUG [SessionImpl] collection initialized
15:51:30,759 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.shoppingLists
15:51:30,759 DEBUG [SessionImpl] initializing collection [it.esselunga.ecommerce.data.model.Person.shoppingLists#58197]
15:51:30,759 DEBUG [SessionImpl] checking second-level cache
15:51:30,759 DEBUG [SessionImpl] collection not cached
15:51:30,759 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:30,759 DEBUG [SQL] select shoppingli0_.SHOPPING_LIST_ID as SHOPPING1___, shoppingli0_.PARTY_ID as PARTY_ID__, shoppingli0_.SHOPPING_LIST_ID as SHOPPING1_0_, shoppingli0_.LASTUPDATED as LASTUPDA2_0_, shoppingli0_.SHOPPING_LIST_NAME as SHOPPING3_0_, shoppingli0_.PARTY_ID as PARTY_ID0_, shoppingli0_.CHANNEL_ID as CHANNEL_ID0_, shoppingli0_.SHOPPING_LIST_TYPE_ID as SHOPPING6_0_, (select count(*) from SHOPPING_LIST_LINE lines where lines.SHOPPING_LIST_ID = shoppingli0_.SHOPPING_LIST_ID) as f1_0_ from SHOPPING_LIST shoppingli0_ where shoppingli0_.PARTY_ID=?
Hibernate: select shoppingli0_.SHOPPING_LIST_ID as SHOPPING1___, shoppingli0_.PARTY_ID as PARTY_ID__, shoppingli0_.SHOPPING_LIST_ID as SHOPPING1_0_, shoppingli0_.LASTUPDATED as LASTUPDA2_0_, shoppingli0_.SHOPPING_LIST_NAME as SHOPPING3_0_, shoppingli0_.PARTY_ID as PARTY_ID0_, shoppingli0_.CHANNEL_ID as CHANNEL_ID0_, shoppingli0_.SHOPPING_LIST_TYPE_ID as SHOPPING6_0_, (select count(*) from SHOPPING_LIST_LINE lines where lines.SHOPPING_LIST_ID = shoppingli0_.SHOPPING_LIST_ID) as f1_0_ from SHOPPING_LIST shoppingli0_ where shoppingli0_.PARTY_ID=?
15:51:30,819 DEBUG [BatcherImpl] preparing statement
15:51:30,819 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:30,819 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:30,839 DEBUG [Loader] result set contains (possibly empty) collection: [it.esselunga.ecommerce.data.model.Person.shoppingLists#58197]
15:51:30,839 DEBUG [SessionImpl] uninitialized collection: initializing
15:51:30,839 DEBUG [Loader] processing result set
15:51:30,849 DEBUG [Loader] done processing result set (0 rows)
15:51:30,849 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:30,849 DEBUG [BatcherImpl] closing statement
15:51:30,849 DEBUG [Loader] total objects hydrated: 0
15:51:30,849 DEBUG [SessionImpl] 1 collections were found in result set
15:51:30,849 DEBUG [SessionImpl] collection fully initialized: [it.esselunga.ecommerce.data.model.Person.shoppingLists#58197]
15:51:30,849 DEBUG [SessionImpl] 1 collections initialized
15:51:30,849 DEBUG [SessionImpl] initializing non-lazy collections
15:51:30,849 DEBUG [SessionImpl] collection initialized
15:51:30,849 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.addresses
15:51:30,849 DEBUG [SessionImpl] initializing collection [it.esselunga.ecommerce.data.model.Person.addresses#58197]
15:51:30,849 DEBUG [SessionImpl] checking second-level cache
15:51:30,849 DEBUG [SessionImpl] collection not cached
15:51:30,849 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:30,849 DEBUG [SQL] select addresses0_.ADDRESS_ID as ADDRESS_ID__, addresses0_.PARTY_ID as PARTY_ID__, addresses0_.ADDRESS_ID as ADDRESS_ID0_, addresses0_.ADDRESS_TYPE as ADDRESS_2_0_, addresses0_.ADDRESSEE as ADDRESSEE0_, addresses0_.COUNTRY as COUNTRY0_, addresses0_.REGION as REGION0_, addresses0_.PROVINCE as PROVINCE0_, addresses0_.COMMUNA as COMMUNA0_, addresses0_.STREET as STREET0_, addresses0_.POSTCODE as POSTCODE0_, addresses0_.HOUSE_NUMBER as HOUSE_N10_0_, addresses0_.PARTY_ID as PARTY_ID0_, addresses0_.TEL as TEL0_, addresses0_.IVA as IVA0_, addresses0_.COMPANY as COMPANY0_ from ADDRESS addresses0_ where addresses0_.PARTY_ID=?
Hibernate: select addresses0_.ADDRESS_ID as ADDRESS_ID__, addresses0_.PARTY_ID as PARTY_ID__, addresses0_.ADDRESS_ID as ADDRESS_ID0_, addresses0_.ADDRESS_TYPE as ADDRESS_2_0_, addresses0_.ADDRESSEE as ADDRESSEE0_, addresses0_.COUNTRY as COUNTRY0_, addresses0_.REGION as REGION0_, addresses0_.PROVINCE as PROVINCE0_, addresses0_.COMMUNA as COMMUNA0_, addresses0_.STREET as STREET0_, addresses0_.POSTCODE as POSTCODE0_, addresses0_.HOUSE_NUMBER as HOUSE_N10_0_, addresses0_.PARTY_ID as PARTY_ID0_, addresses0_.TEL as TEL0_, addresses0_.IVA as IVA0_, addresses0_.COMPANY as COMPANY0_ from ADDRESS addresses0_ where addresses0_.PARTY_ID=?
15:51:30,859 DEBUG [BatcherImpl] preparing statement
15:51:30,859 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:30,859 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:30,899 DEBUG [Loader] result set contains (possibly empty) collection: [it.esselunga.ecommerce.data.model.Person.addresses#58197]
15:51:30,899 DEBUG [SessionImpl] uninitialized collection: initializing
15:51:30,899 DEBUG [Loader] processing result set
15:51:30,909 DEBUG [Loader] done processing result set (0 rows)
15:51:30,909 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:30,909 DEBUG [BatcherImpl] closing statement
15:51:30,909 DEBUG [Loader] total objects hydrated: 0
15:51:30,909 DEBUG [SessionImpl] 1 collections were found in result set
15:51:30,909 DEBUG [SessionImpl] collection fully initialized: [it.esselunga.ecommerce.data.model.Person.addresses#58197]
15:51:30,909 DEBUG [SessionImpl] 1 collections initialized
15:51:30,909 DEBUG [SessionImpl] initializing non-lazy collections
15:51:30,909 DEBUG [SessionImpl] collection initialized
15:51:30,909 DEBUG [Cascades] done processing cascades for: it.esselunga.ecommerce.data.model.Person
15:51:30,919 DEBUG [Cascades] processing cascades for: it.esselunga.ecommerce.data.model.Person
15:51:30,919 DEBUG [Cascades] done processing cascades for: it.esselunga.ecommerce.data.model.Person
15:51:30,919 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate.SessionHolder@2ee7e5] for key [net.sf.hibernate.impl.SessionFactoryImpl@69695f] bound to thread [main]
15:51:30,919 DEBUG [SessionImpl] flushing session
15:51:30,919 DEBUG [Cascades] processing cascades for: it.esselunga.ecommerce.data.model.Customer
15:51:30,919 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Customer.deliveryAddresses
15:51:30,919 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.userLogins
15:51:30,919 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.shoppingLists
15:51:30,919 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.addresses
15:51:30,919 DEBUG [Cascades] done processing cascades for: it.esselunga.ecommerce.data.model.Customer
15:51:30,919 DEBUG [SessionImpl] Collection dirty: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58195]
15:51:30,919 DEBUG [SessionImpl] Flushing entities and processing referenced collections
15:51:30,919 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Customer.deliveryAddresses#58195], was: [it.esselunga.ecommerce.data.model.Customer.deliveryAddresses#58195]
15:51:30,919 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.userLogins#58195], was: [it.esselunga.ecommerce.data.model.Person.userLogins#58195]
15:51:30,919 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.trolleys#58195], was: [it.esselunga.ecommerce.data.model.Person.trolleys#58195]
15:51:30,929 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.shoppingLists#58195], was: [it.esselunga.ecommerce.data.model.Person.shoppingLists#58195]
15:51:30,929 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.addresses#58195], was: [it.esselunga.ecommerce.data.model.Person.addresses#58195]
15:51:30,929 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58195], was: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58195]
15:51:30,929 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Party.relatedPartiesTo#58195], was: [it.esselunga.ecommerce.data.model.Party.relatedPartiesTo#58195]
15:51:30,929 DEBUG [SessionImpl] Processing unreferenced collections
15:51:30,929 DEBUG [SessionImpl] Collection dereferenced: [it.esselunga.ecommerce.data.model.Person.userLogins#58197]
15:51:30,929 DEBUG [SessionImpl] Collection dereferenced: [it.esselunga.ecommerce.data.model.Person.trolleys#58197]
15:51:30,929 DEBUG [SessionImpl] Collection dereferenced: [it.esselunga.ecommerce.data.model.Person.shoppingLists#58197]
15:51:30,929 DEBUG [SessionImpl] Collection dereferenced: [it.esselunga.ecommerce.data.model.Person.addresses#58197]
15:51:30,929 DEBUG [SessionImpl] Collection dereferenced: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58197]
15:51:30,929 DEBUG [SessionImpl] Collection dereferenced: [it.esselunga.ecommerce.data.model.Party.relatedPartiesTo#58197]
15:51:30,929 DEBUG [SessionImpl] Scheduling collection removes/(re)creates/updates
15:51:30,929 DEBUG [SessionImpl] Flushed: 0 insertions, 0 updates, 1 deletions to 4 objects
15:51:30,929 DEBUG [SessionImpl] Flushed: 0 (re)creations, 1 updates, 6 removals to 13 collections
15:51:30,929 DEBUG [Printer] listing entities:
15:51:30,929 DEBUG [Printer] it.esselunga.ecommerce.data.model.EducationLevel{enumId=2215, description=il livello di educazione della laurea, enumCode=laurea, sequence=1}
15:51:30,929 DEBUG [Printer] it.esselunga.ecommerce.data.model.Customer{partyId=58195, addresses=uninitialized, title=Mr., homeTel=02-57402284, sendInfo=true, relatedPartiesTo=uninitialized, sex=M, fidelityCardNumber=601724305345034, partyType=2, relatedPartiesFrom=[], forename=pluto, deliveryAddresses=uninitialized, howManyRelatives=2, fidelityCardType=GOLD , educationLevel=EducationLevel#2215, creationDate=07 maggio 2004 15:50:11, shoppingLists=uninitialized, profession=Profession#2214, newCardNumber=true, surname=pippo, dateOfBirth=13 febbraio 1973 15:50:11, detailsPrivate=true, userLogins=uninitialized, workTel=347-0077078, email=pippo@pluto.com, trolleys=uninitialized, mobileTel=347-0077078}
15:51:30,939 DEBUG [Printer] it.esselunga.ecommerce.data.model.Profession{enumId=2214, description=il mestiere piu antico del mondo, enumCode=ingegnere, sequence=1}
15:51:30,939 DEBUG [Printer] it.esselunga.ecommerce.data.model.Person{addresses=[], partyId=58197, forename=cognome1, title=Mr., educationLevel=EducationLevel#2215, profession=Profession#2214, shoppingLists=[], creationDate=07 maggio 2004 15:50:35, homeTel=02-57402284, relatedPartiesTo=uninitialized, sex=M, surname=parente1, dateOfBirth=11 novembre 1976 15:50:35, detailsPrivate=true, partyType=2, userLogins=[], email=email-parente1@updatecustomer.it, workTel=347-0077078, relatedPartiesFrom=uninitialized, trolleys=uninitialized, mobileTel=347-0077078}
15:51:30,949 DEBUG [SessionImpl] executing flush
15:51:30,949 DEBUG [BasicCollectionPersister] Deleting collection: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58197]
15:51:30,949 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:30,949 DEBUG [SQL] delete from PARTY_RELATIONSHIP where PARTY_ID_TO=?
Hibernate: delete from PARTY_RELATIONSHIP where PARTY_ID_TO=?
15:51:30,949 DEBUG [BatcherImpl] preparing statement
15:51:30,949 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:30,949 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:30,949 DEBUG [BatcherImpl] Adding to batch
15:51:30,949 DEBUG [BasicCollectionPersister] done deleting collection
15:51:30,949 DEBUG [BatcherImpl] Executing batch size: 1
15:51:30,959 DEBUG [BatcherImpl] success of batch update unknown: 0
15:51:30,959 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:30,959 DEBUG [BatcherImpl] closing statement
15:51:30,989 DEBUG [BasicCollectionPersister] Deleting collection: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58195]
15:51:30,989 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:30,989 DEBUG [SQL] delete from PARTY_RELATIONSHIP where PARTY_ID_TO=?
Hibernate: delete from PARTY_RELATIONSHIP where PARTY_ID_TO=?
15:51:30,989 DEBUG [BatcherImpl] preparing statement
15:51:30,989 DEBUG [IntegerType] binding '58195' to parameter: 1
15:51:30,989 DEBUG [IntegerType] binding '58195' to parameter: 1
15:51:30,989 DEBUG [BatcherImpl] Adding to batch
15:51:30,989 DEBUG [BasicCollectionPersister] done deleting collection
15:51:30,989 DEBUG [BatcherImpl] Executing batch size: 1
15:51:30,999 DEBUG [BatcherImpl] success of batch update unknown: 0
15:51:30,999 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:30,999 DEBUG [BatcherImpl] closing statement
15:51:30,999 DEBUG [NormalizedEntityPersister] Deleting entity: [it.esselunga.ecommerce.data.model.Person#58197]
15:51:30,999 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:30,999 DEBUG [SQL] delete from PARTY where PARTY_ID=?
Hibernate: delete from PARTY where PARTY_ID=?
15:51:30,999 DEBUG [BatcherImpl] preparing statement
15:51:30,999 DEBUG [BatcherImpl] about to open: 1 open PreparedStatements, 0 open ResultSets
15:51:31,009 DEBUG [SQL] delete from PERSON where PARTY_ID=?
Hibernate: delete from PERSON where PARTY_ID=?
15:51:31,009 DEBUG [BatcherImpl] preparing statement
15:51:31,009 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:31,009 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:31,019 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:31,019 DEBUG [IntegerType] binding '58197' to parameter: 1
15:51:31,029 DEBUG [BatcherImpl] done closing: 1 open PreparedStatements, 0 open ResultSets
15:51:31,029 DEBUG [BatcherImpl] closing statement
15:51:31,029 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:31,029 DEBUG [BatcherImpl] closing statement
15:51:31,039 DEBUG [SessionImpl] post flush
15:51:31,039 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate.SessionHolder@2ee7e5] for key [net.sf.hibernate.impl.SessionFactoryImpl@69695f] bound to thread [main]
15:51:31,039 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:31,039 DEBUG [SQL] select PARTY_SEQ.nextval from dual
Hibernate: select PARTY_SEQ.nextval from dual
15:51:31,039 DEBUG [BatcherImpl] preparing statement
15:51:31,069 DEBUG [SequenceGenerator] Sequence identifier generated: 58198
15:51:31,069 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:31,069 DEBUG [BatcherImpl] closing statement
15:51:31,069 DEBUG [SessionImpl] generated identifier: 58198
15:51:31,069 DEBUG [SessionImpl] saving [it.esselunga.ecommerce.data.model.Person#58198]
15:51:31,069 DEBUG [Cascades] processing cascades for: it.esselunga.ecommerce.data.model.Person
15:51:31,079 DEBUG [Cascades] done processing cascades for: it.esselunga.ecommerce.data.model.Person
15:51:31,079 DEBUG [Cascades] id unsaved-value strategy NULL
15:51:31,079 DEBUG [Cascades] id unsaved-value strategy NULL
15:51:31,079 DEBUG [Cascades] processing cascades for: it.esselunga.ecommerce.data.model.Person
15:51:31,079 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.userLogins
15:51:31,079 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.shoppingLists
15:51:31,079 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.addresses
15:51:31,079 DEBUG [Cascades] done processing cascades for: it.esselunga.ecommerce.data.model.Person
15:51:31,079 DEBUG [HibernateInterceptor] Not closing pre-bound Hibernate session after interceptor
15:51:31,079 DEBUG [TransactionInterceptor] Invoking commit for transaction on method 'updateCustomer' in class [it.esselunga.ecommerce.services.party.PartyService]
15:51:31,079 DEBUG [HibernateTransactionManager] Triggering beforeCommit synchronization
15:51:31,079 DEBUG [HibernateTransactionManager] Triggering beforeCompletion synchronization
15:51:31,089 INFO [HibernateTransactionManager] Initiating transaction commit
15:51:31,089 DEBUG [HibernateTransactionManager] Committing Hibernate transaction on session [net.sf.hibernate.impl.SessionImpl@1e064c]
15:51:31,089 DEBUG [JDBCTransaction] commit
15:51:31,089 DEBUG [SessionImpl] flushing session
15:51:31,089 DEBUG [Cascades] processing cascades for: it.esselunga.ecommerce.data.model.Customer
15:51:31,089 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Customer.deliveryAddresses
15:51:31,099 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.userLogins
15:51:31,099 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.shoppingLists
15:51:31,099 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.addresses
15:51:31,099 DEBUG [Cascades] done processing cascades for: it.esselunga.ecommerce.data.model.Customer
15:51:31,099 DEBUG [Cascades] processing cascades for: it.esselunga.ecommerce.data.model.Person
15:51:31,099 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.userLogins
15:51:31,099 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.shoppingLists
15:51:31,099 DEBUG [Cascades] cascading to collection: it.esselunga.ecommerce.data.model.Person.addresses
15:51:31,099 DEBUG [Cascades] done processing cascades for: it.esselunga.ecommerce.data.model.Person
15:51:31,099 DEBUG [SessionImpl] Collection dirty: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58195]
15:51:31,099 DEBUG [SessionImpl] Flushing entities and processing referenced collections
15:51:31,099 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Customer.deliveryAddresses#58195], was: [it.esselunga.ecommerce.data.model.Customer.deliveryAddresses#58195]
15:51:31,109 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.userLogins#58195], was: [it.esselunga.ecommerce.data.model.Person.userLogins#58195]
15:51:31,109 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.trolleys#58195], was: [it.esselunga.ecommerce.data.model.Person.trolleys#58195]
15:51:31,109 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.shoppingLists#58195], was: [it.esselunga.ecommerce.data.model.Person.shoppingLists#58195]
15:51:31,109 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.addresses#58195], was: [it.esselunga.ecommerce.data.model.Person.addresses#58195]
15:51:31,109 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58195], was: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58195]
15:51:31,109 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Party.relatedPartiesTo#58195], was: [it.esselunga.ecommerce.data.model.Party.relatedPartiesTo#58195]
15:51:31,129 DEBUG [WrapVisitor] Wrapped collection in role: it.esselunga.ecommerce.data.model.Person.userLogins
15:51:31,129 DEBUG [WrapVisitor] Wrapped collection in role: it.esselunga.ecommerce.data.model.Person.trolleys
15:51:31,129 DEBUG [WrapVisitor] Wrapped collection in role: it.esselunga.ecommerce.data.model.Person.shoppingLists
15:51:31,129 DEBUG [WrapVisitor] Wrapped collection in role: it.esselunga.ecommerce.data.model.Person.addresses
15:51:31,129 DEBUG [WrapVisitor] Wrapped collection in role: it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom
15:51:31,129 DEBUG [WrapVisitor] Wrapped collection in role: it.esselunga.ecommerce.data.model.Party.relatedPartiesTo
15:51:31,129 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.userLogins#58198], was: [<unreferenced>]
15:51:31,129 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.trolleys#58198], was: [<unreferenced>]
15:51:31,139 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.shoppingLists#58198], was: [<unreferenced>]
15:51:31,139 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Person.addresses#58198], was: [<unreferenced>]
15:51:31,139 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58198], was: [<unreferenced>]
15:51:31,139 DEBUG [SessionImpl] Collection found: [it.esselunga.ecommerce.data.model.Party.relatedPartiesTo#58198], was: [<unreferenced>]
15:51:31,139 DEBUG [SessionImpl] Processing unreferenced collections
15:51:31,139 DEBUG [SessionImpl] Scheduling collection removes/(re)creates/updates
15:51:31,139 DEBUG [SessionImpl] Flushed: 1 insertions, 0 updates, 0 deletions to 4 objects
15:51:31,139 DEBUG [SessionImpl] Flushed: 6 (re)creations, 1 updates, 0 removals to 19 collections
15:51:31,139 DEBUG [Printer] listing entities:
15:51:31,139 DEBUG [Printer] it.esselunga.ecommerce.data.model.Person{addresses=[], partyId=58198, forename=cognome2, title=Mr., educationLevel=EducationLevel#2215, profession=Profession#2214, shoppingLists=[], creationDate=07 maggio 2004 15:51:13, homeTel=02-57402284, relatedPartiesTo=[PartyRelationship{relationshipType=RelativeType#2213, throughDate=null, relatedParty=Customer#58195, description=null, fromDate=null}], sex=M, surname=parente2, dateOfBirth=11 novembre 1976 15:51:13, detailsPrivate=true, partyType=2, userLogins=[], email=email-parente2@updatecustomer.it, workTel=347-0077078, relatedPartiesFrom=[], trolleys=[], mobileTel=347-0077078}
15:51:31,139 DEBUG [Printer] it.esselunga.ecommerce.data.model.EducationLevel{enumId=2215, description=il livello di educazione della laurea, enumCode=laurea, sequence=1}
15:51:31,139 DEBUG [Printer] it.esselunga.ecommerce.data.model.Customer{partyId=58195, addresses=uninitialized, title=Mr., homeTel=02-57402284, sendInfo=true, relatedPartiesTo=uninitialized, sex=M, fidelityCardNumber=601724305345034, partyType=2, relatedPartiesFrom=[PartyRelationship{relationshipType=RelativeType#2213, throughDate=null, relatedParty=Person#58198, description=null, fromDate=null}], forename=pluto, deliveryAddresses=uninitialized, howManyRelatives=2, fidelityCardType=GOLD , educationLevel=EducationLevel#2215, creationDate=07 maggio 2004 15:50:11, shoppingLists=uninitialized, profession=Profession#2214, newCardNumber=true, surname=pippo, dateOfBirth=13 febbraio 1973 15:50:11, detailsPrivate=true, userLogins=uninitialized, workTel=347-0077078, email=pippo@pluto.com, trolleys=uninitialized, mobileTel=347-0077078}
15:51:31,149 DEBUG [Printer] it.esselunga.ecommerce.data.model.Profession{enumId=2214, description=il mestiere piu antico del mondo, enumCode=ingegnere, sequence=1}
15:51:31,149 DEBUG [SessionImpl] executing flush
15:51:31,149 DEBUG [NormalizedEntityPersister] Inserting entity: [it.esselunga.ecommerce.data.model.Person#58198]
15:51:31,149 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:31,149 DEBUG [SQL] insert into PARTY (PARTY_TYPE, PARTY_ID) values (?, ?)
Hibernate: insert into PARTY (PARTY_TYPE, PARTY_ID) values (?, ?)
15:51:31,149 DEBUG [BatcherImpl] preparing statement
15:51:31,149 DEBUG [BatcherImpl] about to open: 1 open PreparedStatements, 0 open ResultSets
15:51:31,149 DEBUG [SQL] insert into PERSON (TITLE, SURNAME, FORENAME, EMAIL, HOME_TEL, WORK_TEL, MOBILE_TEL, DATE_OF_BIRTH, SEX, DETAILS_PRIVATE, CREATION_DATE, PROFESSION_ID, EDUCATION_LEVEL_ID, PARTY_ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
Hibernate: insert into PERSON (TITLE, SURNAME, FORENAME, EMAIL, HOME_TEL, WORK_TEL, MOBILE_TEL, DATE_OF_BIRTH, SEX, DETAILS_PRIVATE, CREATION_DATE, PROFESSION_ID, EDUCATION_LEVEL_ID, PARTY_ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
15:51:31,149 DEBUG [BatcherImpl] preparing statement
15:51:31,149 DEBUG [NormalizedEntityPersister] Dehydrating entity: [it.esselunga.ecommerce.data.model.Person#58198]
15:51:31,149 DEBUG [PersistentEnumType] binding '2' to parameter: 1
15:51:31,149 DEBUG [PersistentEnumType] binding '2' to parameter: 1
15:51:31,149 DEBUG [IntegerType] binding '58198' to parameter: 2
15:51:31,149 DEBUG [IntegerType] binding '58198' to parameter: 2
15:51:31,149 DEBUG [StringType] binding 'Mr.' to parameter: 1
15:51:31,149 DEBUG [StringType] binding 'Mr.' to parameter: 1
15:51:31,149 DEBUG [StringType] binding 'parente2' to parameter: 2
15:51:31,149 DEBUG [StringType] binding 'parente2' to parameter: 2
15:51:31,149 DEBUG [StringType] binding 'cognome2' to parameter: 3
15:51:31,149 DEBUG [StringType] binding 'cognome2' to parameter: 3
15:51:31,149 DEBUG [StringType] binding
'email-parente2@updatecustomer.it' to parameter: 4
15:51:31,149 DEBUG [StringType] binding
'email-parente2@updatecustomer.it' to parameter: 4
15:51:31,149 DEBUG [StringType] binding '02-57402284' to parameter: 5
15:51:31,149 DEBUG [StringType] binding '02-57402284' to parameter: 5
15:51:31,159 DEBUG [StringType] binding '347-0077078' to parameter: 6
15:51:31,159 DEBUG [StringType] binding '347-0077078' to parameter: 6
15:51:31,159 DEBUG [StringType] binding '347-0077078' to parameter: 7
15:51:31,159 DEBUG [StringType] binding '347-0077078' to parameter: 7
15:51:31,159 DEBUG [TimestampType] binding '11 novembre 1976 15:51:13' to parameter: 8
15:51:31,159 DEBUG [TimestampType] binding '11 novembre 1976 15:51:13' to parameter: 8
15:51:31,159 DEBUG [StringType] binding 'M' to parameter: 9
15:51:31,159 DEBUG [StringType] binding 'M' to parameter: 9
15:51:31,159 DEBUG [BooleanType] binding 'true' to parameter: 10
15:51:31,159 DEBUG [BooleanType] binding 'true' to parameter: 10
15:51:31,159 DEBUG [TimestampType] binding '07 maggio 2004 15:51:13' to parameter: 11
15:51:31,159 DEBUG [TimestampType] binding '07 maggio 2004 15:51:13' to parameter: 11
15:51:31,159 DEBUG [Cascades] id unsaved-value strategy NULL
15:51:31,159 DEBUG [IntegerType] binding '2214' to parameter: 12
15:51:31,159 DEBUG [IntegerType] binding '2214' to parameter: 12
15:51:31,159 DEBUG [Cascades] id unsaved-value strategy NULL
15:51:31,159 DEBUG [IntegerType] binding '2215' to parameter: 13
15:51:31,159 DEBUG [IntegerType] binding '2215' to parameter: 13
15:51:31,159 DEBUG [IntegerType] binding '58198' to parameter: 14
15:51:31,159 DEBUG [IntegerType] binding '58198' to parameter: 14
15:51:31,189 DEBUG [BatcherImpl] done closing: 1 open PreparedStatements, 0 open ResultSets
15:51:31,189 DEBUG [BatcherImpl] closing statement
15:51:31,189 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:31,189 DEBUG [BatcherImpl] closing statement
15:51:31,199 DEBUG [BasicCollectionPersister] Deleting rows of collection: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58195]
15:51:31,199 DEBUG [BasicCollectionPersister] no rows to delete
15:51:31,199 DEBUG [BasicCollectionPersister] Updating rows of collection: it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58195
15:51:31,199 DEBUG [BasicCollectionPersister] done updating rows: 0 updated
15:51:31,199 DEBUG [BasicCollectionPersister] Inserting rows of collection: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58195]
15:51:31,199 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
15:51:31,199 DEBUG [SQL] insert into PARTY_RELATIONSHIP (PARTY_ID_TO, FROM_DATE, THRU_DATE, DESCRIPTION, RELATIONSHIP_TYPE_ID, PARTY_ID_FROM) values (?, ?, ?, ?, ?, ?)
Hibernate: insert into PARTY_RELATIONSHIP (PARTY_ID_TO, FROM_DATE, THRU_DATE, DESCRIPTION, RELATIONSHIP_TYPE_ID, PARTY_ID_FROM) values (?, ?, ?, ?, ?, ?)
15:51:31,199 DEBUG [BatcherImpl] preparing statement
15:51:31,199 DEBUG [IntegerType] binding '58195' to parameter: 1
15:51:31,199 DEBUG [IntegerType] binding '58195' to parameter: 1
15:51:31,199 DEBUG [TimestampType] binding null to parameter: 2
15:51:31,199 DEBUG [TimestampType] binding null to parameter: 2
15:51:31,199 DEBUG [TimestampType] binding null to parameter: 3
15:51:31,199 DEBUG [TimestampType] binding null to parameter: 3
15:51:31,199 DEBUG [StringType] binding null to parameter: 4
15:51:31,199 DEBUG [StringType] binding null to parameter: 4
15:51:31,199 DEBUG [Cascades] id unsaved-value strategy NULL
15:51:31,199 DEBUG [IntegerType] binding '2213' to parameter: 5
15:51:31,199 DEBUG [IntegerType] binding '2213' to parameter: 5
15:51:31,199 DEBUG [IntegerType] binding '58198' to parameter: 6
15:51:31,199 DEBUG [IntegerType] binding '58198' to parameter: 6
15:51:31,199 DEBUG [BatcherImpl] Adding to batch
15:51:31,199 DEBUG [BasicCollectionPersister] done inserting rows: 1 inserted
15:51:31,199 DEBUG [BatcherImpl] Executing batch size: 1
15:51:31,219 DEBUG [BatcherImpl] success of batch update unknown: 0
15:51:31,219 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
15:51:31,219 DEBUG [BatcherImpl] closing statement
15:51:31,219 DEBUG [BasicCollectionPersister] Inserting collection: [it.esselunga.ecommerce.data.model.Party.relatedPartiesFrom#58198]
15:51:31,219 DEBUG [BasicCollectionPersister] collection was empty
15:51:31,219 DEBUG [SessionImpl] post flush
15:51:31,249 DEBUG [SessionImpl] transaction completion
15:51:31,249 DEBUG [JDBCTransaction] re-enabling autocommit
15:51:31,249 DEBUG [HibernateTransactionManager] Triggering afterCompletion synchronization
15:51:31,249 DEBUG [TransactionSynchronizationManager] Clearing transaction synchronization
15:51:31,249 DEBUG [TransactionSynchronizationManager] Removed value [org.springframework.jdbc.datasource.ConnectionHolder@17aaa0e] for key [org.apache.commons.dbcp.BasicDataSource@d7ffbf] from thread [main]
15:51:31,249 DEBUG [TransactionSynchronizationManager] Removed value [org.springframework.orm.hibernate.SessionHolder@2ee7e5] for key [net.sf.hibernate.impl.SessionFactoryImpl@69695f] from thread [main]
15:51:31,249 DEBUG [HibernateTransactionManager] Closing Hibernate session [net.sf.hibernate.impl.SessionImpl@1e064c] after transaction
15:51:31,249 DEBUG [SessionFactoryUtils] Closing Hibernate session
15:51:31,249 DEBUG [SessionImpl] closing session
15:51:31,249 DEBUG [SessionImpl] disconnecting session
15:51:31,259 DEBUG [SessionImpl] transaction completion
15:51:31,259 DEBUG [TransactionInterceptor] Getting transaction for method 'getPersonRelatives' in class [it.esselunga.ecommerce.services.party.PartyService]
15:51:31,259 DEBUG [HibernateTransactionManager] Using transaction object [org.springframework.orm.hibernate.HibernateTransactionObject@92eb76]
15:51:31,259 DEBUG [HibernateTransactionManager] Creating new transaction
15:51:31,259 DEBUG [SessionFactoryUtils] Opening Hibernate session
15:51:31,259 DEBUG [SessionImpl] opened session
15:51:31,259 DEBUG [HibernateTransactionManager] Opened new session [net.sf.hibernate.impl.SessionImpl@1a0b94d] for Hibernate transaction
15:51:31,259 DEBUG [HibernateTransactionManager] Beginning Hibernate transaction on session [net.sf.hibernate.impl.SessionImpl@1a0b94d]
15:51:31,259 DEBUG [JDBCTransaction] begin
15:51:31,299 DEBUG [JDBCTransaction] current autocommit status:true
15:51:31,299 DEBUG [JDBCTransaction] disabling autocommit
15:51:31,299 DEBUG [TransactionSynchronizationManager] Bound value [org.springframework.orm.hibernate.SessionHolder@f8ae79] for key [net.sf.hibernate.impl.SessionFactoryImpl@69695f] to thread [main]
15:51:31,299 DEBUG [TransactionSynchronizationManager] Bound value [org.springframework.jdbc.datasource.ConnectionHolder@86b376] for key [org.apache.commons.dbcp.BasicDataSource@d7ffbf] to thread [main]
15:51:31,299 DEBUG [TransactionSynchronizationManager] Initializing transaction synchronization
15:51:31,299 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate.SessionHolder@f8ae79] for key [net.sf.hibernate.impl.SessionFactoryImpl@69695f] bound to thread [main]
15:51:31,299 DEBUG [HibernateInterceptor] Found thread-bound session for Hibernate interceptor
15:51:31,299 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate.SessionHolder@f8ae79] for key [net.sf.hibernate.impl.SessionFactoryImpl@69695f] bound to thread [main]
15:51:31,309 DEBUG [SessionImpl] find: select relationship.relatedParty from Person p join p.relatedPartiesFrom relationship where p.id=? and relationship.relationshipType.class=it.esselunga.ecommerce.data.model.RelativeType
15:51:31,309 DEBUG [QueryParameters] parameters: [58195]
15:51:31,309 DEBUG [SessionImpl] flushing session
15:51:31,309 DEBUG [SessionImpl] Flushing entities and processing referenced collections
15:51:31,309 DEBUG [SessionImpl] Processing unreferenced collections
15:51:31,309 DEBUG [SessionImpl] Scheduling collection removes/(re)creates/updates
15:51:31,309 DEBUG [SessionImpl] Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
15:51:31,309 DEBUG [SessionImpl] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
15:51:31,309 DEBUG [SessionImpl] Dont need to execute flush
15:51:31,309 DEBUG [QueryTranslator] HQL: select relationship.relatedParty from it.esselunga.ecommerce.data.model.Person p join p.relatedPartiesFrom relationship where p.id=? and relationship.relationshipType.class=it.esselunga.ecommerce.data.model.RelativeType
15:51:31,309 DEBUG [QueryTranslator] SQL: select party3_.PARTY_ID as PARTY_ID, decode (party3_.PARTY_ID, party3__2_.PARTY_ID, 1, party3__1_.PARTY_ID, 2, party3__3_.PARTY_ID, 3,0 ) as clazz_, party3_.PARTY_TYPE as PARTY_TYPE8_, party3__1_.TITLE as TITLE10_, party3__1_.SURNAME as SURNAME10_, party3__1_.FORENAME as FORENAME10_, party3__1_.EMAIL as EMAIL10_, party3__1_.HOME_TEL as HOME_TEL10_, party3__1_.WORK_TEL as WORK_TEL10_, party3__1_.MOBILE_TEL as MOBILE_TEL10_, party3__1_.DATE_OF_BIRTH as DATE_OF_9_10_, party3__1_.SEX as SEX10_, party3__1_.DETAILS_PRIVATE as DETAILS11_10_, party3__1_.CREATION_DATE as CREATIO12_10_, party3__1_.PROFESSION_ID as PROFESS13_10_, party3__1_.EDUCATION_LEVEL_ID as EDUCATI14_10_, party3__2_.FIDELITY_CARD_TYPE as FIDELITY2_11_, party3__2_.FIDELITY_CARD_NUMBER as FIDELITY3_11_, party3__2_.IS_NEW_CARD_NUMBER as IS_NEW_C4_11_, party3__2_.HOW_MANY_RELATIVES as HOW_MANY5_11_, party3__2_.SEND_INFO as SEND_INFO11_, party3__3_.GROUP_NAME as GROUP_NAME12_, party3__3_.DESCRIPTION as DESCRIPT3_12_ from PERSON person0_, PARTY person0__1_, PARTY_RELATIONSHIP relatedpar1_, ENUMERATION partyrelat2_, PARTY party3_, PERSON party3__1_, CUSTOMER party3__2_, PARTY_GROUP party3__3_ where person0_.PARTY_ID=person0__1_.PARTY_ID and person0_.PARTY_ID=relatedpar1_.PARTY_ID_TO and relatedpar1_.PARTY_ID_FROM=party3_.PARTY_ID a