-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 4 posts ] 
Author Message
 Post subject: Query runs lower and lower.
PostPosted: Thu Aug 28, 2008 10:06 am 
Newbie

Joined: Tue Jun 10, 2008 3:51 am
Posts: 10
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)


Top
 Profile  
 
 Post subject:
PostPosted: Fri Aug 29, 2008 3:04 am 
Newbie

Joined: Tue Jul 22, 2008 10:46 pm
Posts: 6
Please use second level cache by default hibernate supports EHCache.


Top
 Profile  
 
 Post subject:
PostPosted: Fri Aug 29, 2008 3:08 am 
Newbie

Joined: Tue Jun 10, 2008 3:51 am
Posts: 10
skr wrote:
Please use second level cache by default hibernate supports EHCache.

Actually, I have configured second-level cache. But it seems that it never hit cache.


Top
 Profile  
 
 Post subject:
PostPosted: Fri Aug 29, 2008 3:51 am 
Newbie

Joined: Tue Jul 22, 2008 10:46 pm
Posts: 6
Actually, I have configured second-level cache. But it seems that it never hit cache.

please post your hibernate configuration and mapping xml file.


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 4 posts ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.