I am calling the same hibernate query twice, the first time, it takes around one minute, but the second time, it takes 4 minutes. Moreover, at the second time, there are much more queries ran compared with the first time call.
I configured
Code:
fetch="join"
to every non-primitive property, so I think there should be only one query when retrieving the entity, but there are much more than I expected.
Here are the logs
First time query:
Quote:
content type : application/x-www-form-urlencoded; charset=UTF-8
2008-08-28 21:50:17,968 INFO [STDOUT] main parameters = [service] : studio [method] : getContest
2008-08-28 21:50:17,968 INFO [STDOUT] received ID = [contest ID] : 2011
2008-08-28 21:50:18,093 INFO [STDOUT] Leave method init.
2008-08-28 21:50:18,093 INFO [STDOUT] Enter method getContest with parameters [2011].
2008-08-28 21:50:18,109 INFO [STDOUT] [Enter method: getContest()]
2008-08-28 21:50:18,109 INFO [STDOUT] [param1: 2,011]
2008-08-28 21:50:18,171 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4996839088574464
2008-08-28 21:50:18,171 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
2008-08-28 21:50:18,171 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
2008-08-28 21:50:18,171 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
2008-08-28 21:50:18,171 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Transaction already joined
2008-08-28 21:50:18,187 DEBUG [org.hibernate.loader.Loader] loading entity: [mycompany.contest.Contest#2011]
2008-08-28 21:50:18,187 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:50:18,187 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:50:19,453 DEBUG [org.hibernate.SQL] /* load mycompany.contest.Contest */ select contest0_.contest_id as contest1_0_24_, contest0_.contest_channel_id as contest2_0_24_, contest0_.name as name0_24_, contest0_.contest_type_id as contest4_0_24_, contest0_.project_id as project5_0_24_, contest0_.tc_direct_project_id as tc6_0_24_, contest0_.contest_detailed_status_id as contest7_0_24_, contest0_.forum_id as forum8_0_24_, contest0_.contest_status_id as contest9_0_24_, contest0_.event_id as event10_0_24_, contest0_.start_time as start11_0_24_, contest0_.end_time as end12_0_24_, contest0_.winner_announcement_time as winner13_0_24_, contest0_.create_user_id as create14_0_24_, contestcha1_.contest_channel_id as contest1_4_0_, contestcha1_.contest_channel_desc as contest2_4_0_, contesttyp2_.contest_type_id as contest1_11_1_, contesttyp2_.contest_type_desc as contest2_11_1_, contesttyp2_.require_preview_file as require3_11_1_, contesttyp2_.require_preview_image as require4_11_1_, conteststa3_.contest_detailed_status_id as contest1_10_2_, conteststa3_.contest_detailed_status_desc as contest2_10_2_, conteststa3_.name as name10_2_, conteststa3_.contest_status_id as contest4_10_2_, submission4_.contest_id as contest4_26_, submission4_.submission_id as submission1_26_, submission4_.submission_id as submission1_25_3_, submission4_.submission_status_id as submission2_25_3_, submission4_.submitter_id as submitter3_25_3_, submission4_.contest_id as contest4_25_3_, submission4_.create_date as create5_25_3_, submission4_.original_file_name as original6_25_3_, submission4_.system_file_name as system7_25_3_, submission4_.submission_type_id as submission8_25_3_, submission4_.mime_type_id as mime9_25_3_, submission4_.rank as rank25_3_, submission4_.submission_date as submission11_25_3_, submission4_.height as height25_3_, submission4_.width as width25_3_, submission4_.modify_date as modify14_25_3_, submission4_.or_submission_id as or15_25_3_, submission4_.path_id as path16_25_3_, submission5_.submission_status_id as submission1_28_4_, submission5_.submission_status_desc as submission2_28_4_, submission6_.submission_type_id as submission1_29_5_, submission6_.submission_type_desc as submission2_29_5_, mimetype7_.mime_type_id as mime1_17_6_, mimetype7_.mime_type_desc as mime2_17_6_, mimetype7_.file_type_id as file3_17_6_, studiofile8_.file_type_id as file1_24_7_, studiofile8_.sort as sort24_7_, studiofile8_.image_file_ind as image3_24_7_, studiofile8_.file_type_desc as file4_24_7_, studiofile8_.extension as extension24_7_, filepath9_.path_id as path1_15_8_, filepath9_.path as path15_8_, filepath9_.modify_date as modify3_15_8_, review10_.submission_id as submission1_27_, review10_.reviewer_id as reviewer2_27_, review10_.submission_id as submission1_27_9_, review10_.reviewer_id as reviewer2_27_9_, review10_.text as text27_9_, review10_.review_status_id as review4_27_9_, review10_.modify_date as modify5_27_9_, reviewstat11_.review_status_id as review1_23_10_, reviewstat11_.review_status_desc as review2_23_10_, prizes12_.submission_id as submission2_28_, prize13_.prize_id as prize1_28_, prize13_.prize_id as prize1_19_11_, prize13_.place as place19_11_, prize13_.amount as amount19_11_, prize13_.prize_type_id as prize4_19_11_, prize13_.create_date as create5_19_11_, contests14_.prize_id as prize1_29_, contest15_.contest_id as contest2_29_, contest15_.contest_id as contest1_0_12_, contest15_.contest_channel_id as contest2_0_12_, contest15_.name as name0_12_, contest15_.contest_type_id as contest4_0_12_, contest15_.project_id as project5_0_12_, contest15_.tc_direct_project_id as tc6_0_12_, contest15_.contest_detailed_status_id as contest7_0_12_, contest15_.forum_id as forum8_0_12_, contest15_.contest_status_id as contest9_0_12_, contest15_.event_id as event10_0_12_, contest15_.start_time as start11_0_12_, contest15_.end_time as end12_0_12_, contest15_.winner_announcement_time as winner13_0_12_, contest15_.create_user_id as create14_0_12_, filetypes16_.contest_id as contest1_30_, studiofile17_.file_type_id as file2_30_, studiofile17_.file_type_id as file1_24_13_, studiofile17_.sort as sort24_13_, studiofile17_.image_file_ind as image3_24_13_, studiofile17_.file_type_desc as file4_24_13_, studiofile17_.extension as extension24_13_, results18_.contest_id as contest1_31_, results18_.submission_id as submission2_31_, results18_.contest_id as contest1_9_14_, results18_.submission_id as submission2_9_14_, results18_.final_score as final3_9_14_, results18_.placed as placed9_14_, results18_.create_date as create5_9_14_, documents19_.contest_id as contest1_32_, document20_.document_id as document2_32_, document20_.document_id as document1_13_15_, document20_.original_file_name as original2_13_15_, document20_.system_file_name as system3_13_15_, document20_.description as descript4_13_15_, document20_.path_id as path5_13_15_, document20_.mime_type_id as mime6_13_15_, document20_.document_type_id as document7_13_15_, document20_.create_date as create8_13_15_, filepath21_.path_id as path1_15_16_, filepath21_.path as path15_16_, filepath21_.modify_date as modify3_15_16_, mimetype22_.mime_type_id as mime1_17_17_, mimetype22_.mime_type_desc as mime2_17_17_, mimetype22_.file_type_id as file3_17_17_, documentty23_.document_type_id as document1_14_18_, documentty23_.document_type_desc as document2_14_18_, media24_.contest_id as contest1_33_, medium25_.medium_id as medium2_33_, medium25_.medium_id as medium1_16_19_, medium25_.medium_desc as medium2_16_19_, config26_.contest_id as contest1_34_, config26_.property_id as property2_34_, config26_.contest_id as contest1_5_20_, config26_.property_id as property2_5_20_, config26_.property_value as property3_5_20_, contestreg27_.contest_id as contest1_35_, contestreg27_.user_id as user2_35_, contestreg27_.contest_id as contest1_8_21_, contestreg27_.user_id as user2_8_21_, contestreg27_.terms_of_use_id as terms3_8_21_, contestreg27_.create_date as create4_8_21_, prizetype28_.prize_type_id as prize1_22_22_, prizetype28_.prize_type_desc as prize2_22_22_, contestres29_.contest_id as contest1_9_23_, contestres29_.submission_id as submission2_9_23_, contestres29_.final_score as final3_9_23_, contestres29_.placed as placed9_23_, contestres29_.create_date as create5_9_23_ from contest contest0_ left outer join contest_channel_lu contestcha1_ on contest0_.contest_channel_id=contestcha1_.contest_channel_id left outer join contest_type_lu contesttyp2_ on contest0_.contest_type_id=contesttyp2_.contest_type_id inner join contest_detailed_status_lu conteststa3_ on contest0_.contest_detailed_status_id=conteststa3_.contest_detailed_status_id left outer join submission submission4_ on contest0_.contest_id=submission4_.contest_id left outer join submission_status_lu submission5_ on submission4_.submission_status_id=submission5_.submission_status_id left outer join submission_type_lu submission6_ on submission4_.submission_type_id=submission6_.submission_type_id left outer join mime_type_lu mimetype7_ on submission4_.mime_type_id=mimetype7_.mime_type_id left outer join file_type_lu studiofile8_ on mimetype7_.file_type_id=studiofile8_.file_type_id left outer join path filepath9_ on submission4_.path_id=filepath9_.path_id left outer join submission_review review10_ on submission4_.submission_id=review10_.submission_id left outer join review_status_lu reviewstat11_ on review10_.review_status_id=reviewstat11_.review_status_id left outer join submission_prize_xref prizes12_ on submission4_.submission_id=prizes12_.submission_id left outer join prize prize13_ on prizes12_.prize_id=prize13_.prize_id left outer join contest_prize_xref contests14_ on prize13_.prize_id=contests14_.prize_id left outer join contest contest15_ on contests14_.contest_id=contest15_.contest_id left outer join contest_file_type_xref filetypes16_ on contest15_.contest_id=filetypes16_.contest_id left outer join file_type_lu studiofile17_ on filetypes16_.file_type_id=studiofile17_.file_type_id left outer join contest_result results18_ on contest15_.contest_id=results18_.contest_id left outer join contest_document_xref documents19_ on contest15_.contest_id=documents19_.contest_id left outer join document document20_ on documents19_.document_id=document20_.document_id left outer join path filepath21_ on document20_.path_id=filepath21_.path_id left outer join mime_type_lu mimetype22_ on document20_.mime_type_id=mimetype22_.mime_type_id left outer join document_type_lu documentty23_ on document20_.document_type_id=documentty23_.document_type_id left outer join contest_medium_xref media24_ on contest15_.contest_id=media24_.contest_id left outer join medium_lu medium25_ on media24_.medium_id=medium25_.medium_id left outer join contest_config config26_ on contest15_.contest_id=config26_.contest_id left outer join contest_registration contestreg27_ on contest15_.contest_id=contestreg27_.contest_id left outer join prize_type_lu prizetype28_ on prize13_.prize_type_id=prizetype28_.prize_type_id left outer join contest_result contestres29_ on submission4_.submission_id=contestres29_.contest_id and submission4_.contest_id=contestres29_.submission_id where contest0_.contest_id=?
2008-08-28 21:50:19,453 INFO [STDOUT] Hibernate: /* load mycompany.contest.Contest */ select contest0_.contest_id as contest1_0_24_, contest0_.contest_channel_id as contest2_0_24_, contest0_.name as name0_24_, contest0_.contest_type_id as contest4_0_24_, contest0_.project_id as project5_0_24_, contest0_.tc_direct_project_id as tc6_0_24_, contest0_.contest_detailed_status_id as contest7_0_24_, contest0_.forum_id as forum8_0_24_, contest0_.contest_status_id as contest9_0_24_, contest0_.event_id as event10_0_24_, contest0_.start_time as start11_0_24_, contest0_.end_time as end12_0_24_, contest0_.winner_announcement_time as winner13_0_24_, contest0_.create_user_id as create14_0_24_, contestcha1_.contest_channel_id as contest1_4_0_, contestcha1_.contest_channel_desc as contest2_4_0_, contesttyp2_.contest_type_id as contest1_11_1_, contesttyp2_.contest_type_desc as contest2_11_1_, contesttyp2_.require_preview_file as require3_11_1_, contesttyp2_.require_preview_image as require4_11_1_, conteststa3_.contest_detailed_status_id as contest1_10_2_, conteststa3_.contest_detailed_status_desc as contest2_10_2_, conteststa3_.name as name10_2_, conteststa3_.contest_status_id as contest4_10_2_, submission4_.contest_id as contest4_26_, submission4_.submission_id as submission1_26_, submission4_.submission_id as submission1_25_3_, submission4_.submission_status_id as submission2_25_3_, submission4_.submitter_id as submitter3_25_3_, submission4_.contest_id as contest4_25_3_, submission4_.create_date as create5_25_3_, submission4_.original_file_name as original6_25_3_, submission4_.system_file_name as system7_25_3_, submission4_.submission_type_id as submission8_25_3_, submission4_.mime_type_id as mime9_25_3_, submission4_.rank as rank25_3_, submission4_.submission_date as submission11_25_3_, submission4_.height as height25_3_, submission4_.width as width25_3_, submission4_.modify_date as modify14_25_3_, submission4_.or_submission_id as or15_25_3_, submission4_.path_id as path16_25_3_, submission5_.submission_status_id as submission1_28_4_, submission5_.submission_status_desc as submission2_28_4_, submission6_.submission_type_id as submission1_29_5_, submission6_.submission_type_desc as submission2_29_5_, mimetype7_.mime_type_id as mime1_17_6_, mimetype7_.mime_type_desc as mime2_17_6_, mimetype7_.file_type_id as file3_17_6_, studiofile8_.file_type_id as file1_24_7_, studiofile8_.sort as sort24_7_, studiofile8_.image_file_ind as image3_24_7_, studiofile8_.file_type_desc as file4_24_7_, studiofile8_.extension as extension24_7_, filepath9_.path_id as path1_15_8_, filepath9_.path as path15_8_, filepath9_.modify_date as modify3_15_8_, review10_.submission_id as submission1_27_, review10_.reviewer_id as reviewer2_27_, review10_.submission_id as submission1_27_9_, review10_.reviewer_id as reviewer2_27_9_, review10_.text as text27_9_, review10_.review_status_id as review4_27_9_, review10_.modify_date as modify5_27_9_, reviewstat11_.review_status_id as review1_23_10_, reviewstat11_.review_status_desc as review2_23_10_, prizes12_.submission_id as submission2_28_, prize13_.prize_id as prize1_28_, prize13_.prize_id as prize1_19_11_, prize13_.place as place19_11_, prize13_.amount as amount19_11_, prize13_.prize_type_id as prize4_19_11_, prize13_.create_date as create5_19_11_, contests14_.prize_id as prize1_29_, contest15_.contest_id as contest2_29_, contest15_.contest_id as contest1_0_12_, contest15_.contest_channel_id as contest2_0_12_, contest15_.name as name0_12_, contest15_.contest_type_id as contest4_0_12_, contest15_.project_id as project5_0_12_, contest15_.tc_direct_project_id as tc6_0_12_, contest15_.contest_detailed_status_id as contest7_0_12_, contest15_.forum_id as forum8_0_12_, contest15_.contest_status_id as contest9_0_12_, contest15_.event_id as event10_0_12_, contest15_.start_time as start11_0_12_, contest15_.end_time as end12_0_12_, contest15_.winner_announcement_time as winner13_0_12_, contest15_.create_user_id as create14_0_12_, filetypes16_.contest_id as contest1_30_, studiofile17_.file_type_id as file2_30_, studiofile17_.file_type_id as file1_24_13_, studiofile17_.sort as sort24_13_, studiofile17_.image_file_ind as image3_24_13_, studiofile17_.file_type_desc as file4_24_13_, studiofile17_.extension as extension24_13_, results18_.contest_id as contest1_31_, results18_.submission_id as submission2_31_, results18_.contest_id as contest1_9_14_, results18_.submission_id as submission2_9_14_, results18_.final_score as final3_9_14_, results18_.placed as placed9_14_, results18_.create_date as create5_9_14_, documents19_.contest_id as contest1_32_, document20_.document_id as document2_32_, document20_.document_id as document1_13_15_, document20_.original_file_name as original2_13_15_, document20_.system_file_name as system3_13_15_, document20_.description as descript4_13_15_, document20_.path_id as path5_13_15_, document20_.mime_type_id as mime6_13_15_, document20_.document_type_id as document7_13_15_, document20_.create_date as create8_13_15_, filepath21_.path_id as path1_15_16_, filepath21_.path as path15_16_, filepath21_.modify_date as modify3_15_16_, mimetype22_.mime_type_id as mime1_17_17_, mimetype22_.mime_type_desc as mime2_17_17_, mimetype22_.file_type_id as file3_17_17_, documentty23_.document_type_id as document1_14_18_, documentty23_.document_type_desc as document2_14_18_, media24_.contest_id as contest1_33_, medium25_.medium_id as medium2_33_, medium25_.medium_id as medium1_16_19_, medium25_.medium_desc as medium2_16_19_, config26_.contest_id as contest1_34_, config26_.property_id as property2_34_, config26_.contest_id as contest1_5_20_, config26_.property_id as property2_5_20_, config26_.property_value as property3_5_20_, contestreg27_.contest_id as contest1_35_, contestreg27_.user_id as user2_35_, contestreg27_.contest_id as contest1_8_21_, contestreg27_.user_id as user2_8_21_, contestreg27_.terms_of_use_id as terms3_8_21_, contestreg27_.create_date as create4_8_21_, prizetype28_.prize_type_id as prize1_22_22_, prizetype28_.prize_type_desc as prize2_22_22_, contestres29_.contest_id as contest1_9_23_, contestres29_.submission_id as submission2_9_23_, contestres29_.final_score as final3_9_23_, contestres29_.placed as placed9_23_, contestres29_.create_date as create5_9_23_ from contest contest0_ left outer join contest_channel_lu contestcha1_ on contest0_.contest_channel_id=contestcha1_.contest_channel_id left outer join contest_type_lu contesttyp2_ on contest0_.contest_type_id=contesttyp2_.contest_type_id inner join contest_detailed_status_lu conteststa3_ on contest0_.contest_detailed_status_id=conteststa3_.contest_detailed_status_id left outer join submission submission4_ on contest0_.contest_id=submission4_.contest_id left outer join submission_status_lu submission5_ on submission4_.submission_status_id=submission5_.submission_status_id left outer join submission_type_lu submission6_ on submission4_.submission_type_id=submission6_.submission_type_id left outer join mime_type_lu mimetype7_ on submission4_.mime_type_id=mimetype7_.mime_type_id left outer join file_type_lu studiofile8_ on mimetype7_.file_type_id=studiofile8_.file_type_id left outer join path filepath9_ on submission4_.path_id=filepath9_.path_id left outer join submission_review review10_ on submission4_.submission_id=review10_.submission_id left outer join review_status_lu reviewstat11_ on review10_.review_status_id=reviewstat11_.review_status_id left outer join submission_prize_xref prizes12_ on submission4_.submission_id=prizes12_.submission_id left outer join prize prize13_ on prizes12_.prize_id=prize13_.prize_id left outer join contest_prize_xref contests14_ on prize13_.prize_id=contests14_.prize_id left outer join contest contest15_ on contests14_.contest_id=contest15_.contest_id left outer join contest_file_type_xref filetypes16_ on contest15_.contest_id=filetypes16_.contest_id left outer join file_type_lu studiofile17_ on filetypes16_.file_type_id=studiofile17_.file_type_id left outer join contest_result results18_ on contest15_.contest_id=results18_.contest_id left outer join contest_document_xref documents19_ on contest15_.contest_id=documents19_.contest_id left outer join document document20_ on documents19_.document_id=document20_.document_id left outer join path filepath21_ on document20_.path_id=filepath21_.path_id left outer join mime_type_lu mimetype22_ on document20_.mime_type_id=mimetype22_.mime_type_id left outer join document_type_lu documentty23_ on document20_.document_type_id=documentty23_.document_type_id left outer join contest_medium_xref media24_ on contest15_.contest_id=media24_.contest_id left outer join medium_lu medium25_ on media24_.medium_id=medium25_.medium_id left outer join contest_config config26_ on contest15_.contest_id=config26_.contest_id left outer join contest_registration contestreg27_ on contest15_.contest_id=contestreg27_.contest_id left outer join prize_type_lu prizetype28_ on prize13_.prize_type_id=prizetype28_.prize_type_id left outer join contest_result contestres29_ on submission4_.submission_id=contestres29_.contest_id and submission4_.contest_id=contestres29_.submission_id where contest0_.contest_id=?
2008-08-28 21:50:21,718 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:50:21,718 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestChannel#2], EntityKey[mycompany.contest.ContestType#14], EntityKey[mycompany.contest.ContestStatus#1], EntityKey[mycompany.submission.Submission#2015], EntityKey[mycompany.submission.SubmissionStatus#1], EntityKey[mycompany.submission.SubmissionType#1], EntityKey[mycompany.contest.MimeType#4], EntityKey[mycompany.contest.StudioFileType#3], EntityKey[mycompany.contest.FilePath#2035], EntityKey[mycompany.submission.SubmissionReview#component[submission,reviewerId]{reviewerId=8520396, submission=mycompany.submission.Submission#2015}], EntityKey[mycompany.submission.ReviewStatus#1], null, null, null, null, null, null, null, null, null, null, null, null, null, EntityKey[mycompany.contest.Contest#2011]
2008-08-28 21:50:21,750 DEBUG [org.hibernate.loader.Loader] found row of collection: [mycompany.contest.Contest.submissions#2011]
2008-08-28 21:50:21,765 DEBUG [org.hibernate.loader.Loader] found row of collection: [mycompany.submission.Submission.review#2015]
2008-08-28 21:50:21,765 DEBUG [org.hibernate.loader.Loader] result set contains (possibly empty) collection: [mycompany.submission.Submission.prizes#2015]
2008-08-28 21:50:24,218 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestChannel#2], EntityKey[mycompany.contest.ContestType#14], EntityKey[mycompany.contest.ContestStatus#1], EntityKey[mycompany.submission.Submission#2016], EntityKey[mycompany.submission.SubmissionStatus#1], EntityKey[mycompany.submission.SubmissionType#1], EntityKey[mycompany.contest.MimeType#4], EntityKey[mycompany.contest.StudioFileType#3], EntityKey[mycompany.contest.FilePath#2036],
The second time query:
Quote:
2008-08-28 21:51:45,531 INFO [STDOUT] main parameters = [service] : studio [method] : getContest
2008-08-28 21:51:45,531 INFO [STDOUT] received ID = [contest ID] : 2011
2008-08-28 21:51:45,531 INFO [STDOUT] Enter method getContest with parameters [2011].
2008-08-28 21:51:45,531 INFO [STDOUT] [Enter method: getContest()]
2008-08-28 21:51:45,531 INFO [STDOUT] [param1: 2,011]
2008-08-28 21:51:45,531 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4996839446654976
2008-08-28 21:51:45,531 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
2008-08-28 21:51:45,531 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
2008-08-28 21:51:45,531 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
2008-08-28 21:51:45,531 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Transaction already joined
2008-08-28 21:51:45,531 DEBUG [org.hibernate.cache.ReadOnlyCache] Cache hit: mycompany.contest.Contest#2011
2008-08-28 21:51:45,531 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [mycompany.contest.ContestStatus#1]
2008-08-28 21:51:45,531 DEBUG [org.hibernate.cache.ReadOnlyCache] Cache hit: mycompany.contest.ContestStatus#1
2008-08-28 21:51:45,531 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:51:45,531 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:51:45,531 INFO [STDOUT] [Enter method: fillToStatuses(ContestStsta)]
2008-08-28 21:51:45,531 INFO [STDOUT] [param1: mycompany.contest.ContestStatus@20]
2008-08-28 21:51:45,546 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
2008-08-28 21:51:45,546 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] dirty checking collections
2008-08-28 21:51:45,546 DEBUG [org.hibernate.engine.Collections] Collection found: [mycompany.contest.Contest.submissions#2011], was: [mycompany.contest.Contest.submissions#2011] (uninitialized)
2008-08-28 21:51:45,546 DEBUG [org.hibernate.engine.Collections] Collection found: [mycompany.contest.Contest.fileTypes#2011], was: [mycompany.contest.Contest.fileTypes#2011] (uninitialized)
2008-08-28 21:51:45,546 DEBUG [org.hibernate.engine.Collections] Collection found: [mycompany.contest.Contest.results#2011], was: [mycompany.contest.Contest.results#2011] (uninitialized)
2008-08-28 21:51:45,546 DEBUG [org.hibernate.engine.Collections] Collection found: [mycompany.contest.Contest.documents#2011], was: [mycompany.contest.Contest.documents#2011] (uninitialized)
2008-08-28 21:51:45,546 DEBUG [org.hibernate.engine.Collections] Collection found: [mycompany.contest.Contest.media#2011], was: [mycompany.contest.Contest.media#2011] (uninitialized)
2008-08-28 21:51:45,546 DEBUG [org.hibernate.engine.Collections] Collection found: [mycompany.contest.Contest.config#2011], was: [mycompany.contest.Contest.config#2011] (uninitialized)
2008-08-28 21:51:45,546 DEBUG [org.hibernate.engine.Collections] Collection found: [mycompany.contest.Contest.contestRegistrations#2011], was: [mycompany.contest.Contest.contestRegistrations#2011] (uninitialized)
2008-08-28 21:51:45,546 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
2008-08-28 21:51:45,546 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 7 collections
2008-08-28 21:51:45,546 DEBUG [org.hibernate.pretty.Printer] listing entities:
2008-08-28 21:51:45,546 DEBUG [org.hibernate.pretty.Printer] mycompany.contest.ContestStatus{contestStatusId=1, description=Unactive - Not Yet Published, statusId=1, name=Unactive - Not Yet Published}
2008-08-28 21:51:45,546 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:51:45,546 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:51:47,218 DEBUG [org.hibernate.SQL] /* dynamic native SQL query */ SELECT csl.* FROM contest_detailed_status_lu csl, contest_detailed_status_relation csr WHERE csl.contest_detailed_status_id = csr.to_contest_status_id AND csr.from_contest_status_id = ?
2008-08-28 21:51:47,218 INFO [STDOUT] Hibernate: /* dynamic native SQL query */ SELECT csl.* FROM contest_detailed_status_lu csl, contest_detailed_status_relation csr WHERE csl.contest_detailed_status_id = csr.to_contest_status_id AND csr.from_contest_status_id = ?
2008-08-28 21:51:48,171 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:51:48,171 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestStatus#6]
2008-08-28 21:51:48,171 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestStatus#1]
2008-08-28 21:51:48,171 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestStatus#2]
2008-08-28 21:51:48,171 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestStatus#3]
2008-08-28 21:51:48,171 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestStatus#4]
2008-08-28 21:51:48,171 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestStatus#5]
2008-08-28 21:51:48,171 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestStatus#7]
2008-08-28 21:51:48,171 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestStatus#8]
2008-08-28 21:51:48,484 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2008-08-28 21:51:48,796 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-08-28 21:51:49,109 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2008-08-28 21:51:49,109 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestStatus#6]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestStatus#6]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestStatus#6
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestStatus#6]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestStatus#2]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestStatus#2]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestStatus#2
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestStatus#2]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestStatus#3]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestStatus#3]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestStatus#3
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestStatus#3]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestStatus#4]
2008-08-28 21:51:49,109 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestStatus#4]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestStatus#4
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestStatus#4]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestStatus#5]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestStatus#5]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestStatus#5
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestStatus#5]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestStatus#7]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestStatus#7]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestStatus#7
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestStatus#7]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestStatus#8]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestStatus#8]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestStatus#8
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestStatus#8]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:51:49,125 INFO [STDOUT] [Exit method: fillToStatuses(ContestStatus)]
2008-08-28 21:51:49,125 INFO [STDOUT] [Exit method: getContest()]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.cache.ReadOnlyCache] Cache hit: mycompany.contest.Contest.contestRegistrations#2011
2008-08-28 21:51:49,125 DEBUG [org.hibernate.loader.Loader] loading entity: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=7346876}]
2008-08-28 21:51:49,125 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:51:49,125 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:51:49,125 DEBUG [org.hibernate.SQL] /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:49,125 INFO [STDOUT] Hibernate: /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:49,796 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:51:49,796 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=7346876}]
2008-08-28 21:51:50,156 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2008-08-28 21:51:50,531 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-08-28 21:51:50,890 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2008-08-28 21:51:50,890 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-08-28 21:51:50,890 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=7346876}]
2008-08-28 21:51:50,890 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=7346876}]
2008-08-28 21:51:50,890 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestRegistration#ContestId: 2,011, UserId: 7,346,876, TermsOfUseId: 20,502, createDate: 06-8-22 ??12:53
2008-08-28 21:51:50,890 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=7346876}]
2008-08-28 21:51:50,890 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:51:50,890 DEBUG [org.hibernate.loader.Loader] done entity load
2008-08-28 21:51:50,890 DEBUG [org.hibernate.loader.Loader] loading entity: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22643127}]
2008-08-28 21:51:50,890 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:51:50,890 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:51:50,890 DEBUG [org.hibernate.SQL] /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:50,890 INFO [STDOUT] Hibernate: /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:51,625 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:51:51,625 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22643127}]
2008-08-28 21:51:51,937 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2008-08-28 21:51:52,250 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-08-28 21:51:52,562 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2008-08-28 21:51:52,562 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-08-28 21:51:52,562 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22643127}]
2008-08-28 21:51:52,562 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22643127}]
2008-08-28 21:51:52,562 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestRegistration#ContestId: 2,011, UserId: 22,643,127, TermsOfUseId: 20,502, createDate: 06-8-27 ??3:15
2008-08-28 21:51:52,562 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22643127}]
2008-08-28 21:51:52,562 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:51:52,562 DEBUG [org.hibernate.loader.Loader] done entity load
2008-08-28 21:51:52,562 DEBUG [org.hibernate.loader.Loader] loading entity: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=15391415}]
2008-08-28 21:51:52,562 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:51:52,562 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:51:52,562 DEBUG [org.hibernate.SQL] /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:52,562 INFO [STDOUT] Hibernate: /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:53,265 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:51:53,265 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=15391415}]
2008-08-28 21:51:53,578 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2008-08-28 21:51:53,890 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-08-28 21:51:54,203 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2008-08-28 21:51:54,203 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-08-28 21:51:54,203 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=15391415}]
2008-08-28 21:51:54,203 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=15391415}]
2008-08-28 21:51:54,203 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestRegistration#ContestId: 2,011, UserId: 15,391,415, TermsOfUseId: 20,502, createDate: 06-8-23 ??9:32
2008-08-28 21:51:54,203 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=15391415}]
2008-08-28 21:51:54,203 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:51:54,203 DEBUG [org.hibernate.loader.Loader] done entity load
2008-08-28 21:51:54,203 DEBUG [org.hibernate.loader.Loader] loading entity: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22640324}]
2008-08-28 21:51:54,203 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:51:54,203 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:51:54,203 DEBUG [org.hibernate.SQL] /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:54,203 INFO [STDOUT] Hibernate: /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:54,859 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:51:54,859 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22640324}]
2008-08-28 21:51:55,265 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2008-08-28 21:51:55,578 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-08-28 21:51:55,890 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2008-08-28 21:51:55,890 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-08-28 21:51:55,890 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22640324}]
2008-08-28 21:51:55,890 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22640324}]
2008-08-28 21:51:55,890 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestRegistration#ContestId: 2,011, UserId: 22,640,324, TermsOfUseId: 20,502, createDate: 06-8-22 ??11:11
2008-08-28 21:51:55,890 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22640324}]
2008-08-28 21:51:55,890 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:51:55,890 DEBUG [org.hibernate.loader.Loader] done entity load
2008-08-28 21:51:55,890 DEBUG [org.hibernate.loader.Loader] loading entity: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22638764}]
2008-08-28 21:51:55,890 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:51:55,890 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:51:55,890 DEBUG [org.hibernate.SQL] /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:55,890 INFO [STDOUT] Hibernate: /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:56,687 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:51:56,687 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22638764}]
2008-08-28 21:51:57,015 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2008-08-28 21:51:57,328 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-08-28 21:51:57,640 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2008-08-28 21:51:57,640 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-08-28 21:51:57,640 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22638764}]
2008-08-28 21:51:57,640 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22638764}]
2008-08-28 21:51:57,640 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestRegistration#ContestId: 2,011, UserId: 22,638,764, TermsOfUseId: 20,502, createDate: 06-8-27 ??6:36
2008-08-28 21:51:57,640 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22638764}]
2008-08-28 21:51:57,640 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:51:57,640 DEBUG [org.hibernate.loader.Loader] done entity load
2008-08-28 21:51:57,640 DEBUG [org.hibernate.loader.Loader] loading entity: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=309156}]
2008-08-28 21:51:57,640 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:51:57,640 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:51:57,640 DEBUG [org.hibernate.SQL] /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:57,640 INFO [STDOUT] Hibernate: /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:58,375 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:51:58,375 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=309156}]
2008-08-28 21:51:58,687 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2008-08-28 21:51:59,000 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-08-28 21:51:59,312 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2008-08-28 21:51:59,312 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-08-28 21:51:59,312 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=309156}]
2008-08-28 21:51:59,312 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=309156}]
2008-08-28 21:51:59,312 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestRegistration#ContestId: 2,011, UserId: 309,156, TermsOfUseId: 20,502, createDate: 06-8-28 ??1:29
2008-08-28 21:51:59,328 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=309156}]
2008-08-28 21:51:59,328 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:51:59,328 DEBUG [org.hibernate.loader.Loader] done entity load
2008-08-28 21:51:59,328 DEBUG [org.hibernate.loader.Loader] loading entity: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22636156}]
2008-08-28 21:51:59,328 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:51:59,328 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:51:59,328 DEBUG [org.hibernate.SQL] /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:59,328 INFO [STDOUT] Hibernate: /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:51:59,968 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:51:59,968 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22636156}]
2008-08-28 21:52:00,312 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2008-08-28 21:52:00,625 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-08-28 21:52:00,937 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2008-08-28 21:52:00,937 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-08-28 21:52:00,937 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22636156}]
2008-08-28 21:52:00,937 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22636156}]
2008-08-28 21:52:00,937 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestRegistration#ContestId: 2,011, UserId: 22,636,156, TermsOfUseId: 20,502, createDate: 06-8-23 ??4:17
2008-08-28 21:52:00,937 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22636156}]
2008-08-28 21:52:00,937 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:52:00,937 DEBUG [org.hibernate.loader.Loader] done entity load
2008-08-28 21:52:00,937 DEBUG [org.hibernate.loader.Loader] loading entity: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22642316}]
2008-08-28 21:52:00,937 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:52:00,937 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:52:00,937 DEBUG [org.hibernate.SQL] /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:52:00,937 INFO [STDOUT] Hibernate: /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:52:01,406 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <.ǚ?, 28 °? 2008 21:52:01>
2008-08-28 21:52:01,406 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
2008-08-28 21:52:01,406 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
2008-08-28 21:52:01,406 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
2008-08-28 21:52:01,640 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:52:01,640 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22642316}]
2008-08-28 21:52:01,953 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2008-08-28 21:52:02,343 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-08-28 21:52:02,656 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2008-08-28 21:52:02,656 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-08-28 21:52:02,656 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22642316}]
2008-08-28 21:52:02,656 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22642316}]
2008-08-28 21:52:02,656 DEBUG [org.hibernate.cache.ReadOnlyCache] Caching: mycompany.contest.ContestRegistration#ContestId: 2,011, UserId: 22,642,316, TermsOfUseId: 20,502, createDate: 06-8-25 ??10:03
2008-08-28 21:52:02,656 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22642316}]
2008-08-28 21:52:02,656 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2008-08-28 21:52:02,656 DEBUG [org.hibernate.loader.Loader] done entity load
2008-08-28 21:52:02,656 DEBUG [org.hibernate.loader.Loader] loading entity: [mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22644609}]
2008-08-28 21:52:02,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-08-28 21:52:02,656 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2008-08-28 21:52:02,656 DEBUG [org.hibernate.SQL] /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:52:02,656 INFO [STDOUT] Hibernate: /* load mycompany.contest.ContestRegistration */ select contestreg0_.contest_id as contest1_8_0_, contestreg0_.user_id as user2_8_0_, contestreg0_.terms_of_use_id as terms3_8_0_, contestreg0_.create_date as create4_8_0_ from contest_registration contestreg0_ where contestreg0_.contest_id=? and contestreg0_.user_id=?
2008-08-28 21:52:03,375 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2008-08-28 21:52:03,375 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[mycompany.contest.ContestRegistration#component[contest,userId]{contest=mycompany.contest.Contest#2011, userId=22644609}]
2008-08-28 21:52:04,593 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2008-08-28 21:52:04,906 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)