Hibernate version:

2.0

Mapping documents:

Code between sessionFactory.openSession() and session.close():

Full stack trace of any exception that occurs:

Name and version of the database you are using:
DB2 UDB 8.0


The generated SQL (show_sql=true):

Debug level Hibernate log excerpt:

We are using c3p0 (0.8.4.5) and hibernate. We set the hibernate.c3p0.max_statements=35, but it does not cache the prepared Statements. It is creating a new one each time and closing it after it is used. What are we missing??

THANKS!!!

How do you detect a new one is created every time ?

Hi bertrand,

Here is how: Please let me know if you have any questions.

Thanks Again,

kjsanchez

Each tablemapping.xml has named sql query like

<sql-query name="globalDataSrcInstanceTBSelect">
<return alias="globalDataSrc" class="com.gs.aml.refs.model.GlobalDataSrcInstanceTB"/>
SELECT {globalDataSrc.*} FROM GLOBAL_DATA_SRC_INSTANCE_TB {globalDataSrc}
WHERE {globalDataSrc}.DATA_SRC_I = :dataSrc
AND {globalDataSrc}.DATA_SRC_ID_I = :dataSrcId
AND {globalDataSrc}.DATA_SRC_SECONDARY_ID_I = :dataSrcSecondaryId
AND {globalDataSrc}.DATA_SRC_FIELD_I = :dataSrcFieldId
</sql-query>

1. REFSHelperClass loads the hibernate configuration and property file.
2. The initialize method creates query object via following statements
Query globalQuery= session.getNamedQuery(REFSConstants.GLOBAL_SELECT_QUERY)
3. These query objects are then ready for use.
4. In the method I populate the query parameter and execute the list() method for query
globalQuery.setParameter(REFSConstants.GLOBAL_SELECT_QUERY_PARAMETER1,_valC);
List foundEntry = globalQuery.list();

if (foundEntry.size() == 0)
{ //save the object
}

The console output shows that the query statements are not chached as prepared statements, and they are always created and closed.

****************************Log file output**************************************
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] about to open: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0]

SELECT global.val_i as val_i0_, global.val_c as val_c0_, global.chg_by_i as chg_by_i0_, global.chg_on_d as chg_on_d0_ FROM GLOBAL_TB global WHERE global.VAL_C = ?

Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] preparing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding 'GARCIA, DANIEL' to parameter: 1
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] processing result set
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] returning '18677' as column: val_i0_
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] result row: 18677
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done processing result set (1 rows)
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done closing: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] closing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] total objects hydrated: 0
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] initializing non-lazy collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] SQL query:

SELECT {globalDataSrc.*} FROM GLOBAL_DATA_SRC_INSTANCE_TB {globalDataSrc}
WHERE {globalDataSrc}.DATA_SRC_I = :dataSrc
AND {globalDataSrc}.DATA_SRC_ID_I = :dataSrcId
AND {globalDataSrc}.DATA_SRC_SECONDARY_ID_I = :dataSrcSecondaryId
AND {globalDataSrc}.DATA_SRC_FIELD_I = :dataSrcFieldId

Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] flushing session
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushing entities and processing referenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Processing unreferenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Scheduling collection removes/(re)creates/updates
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 0 insertions, 0 updates, 0 deletions to 41 objects
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
ed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Dont need to execute flush
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] about to open: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0]

SELECT globalDataSrc.unique_hit_id_i as unique_h1_0_, globalDataSrc.data_src_i as data_src_i0_, globalDataSrc.data_src_id_i as data_src3_0_, globalDataSrc.data_src_secondary_id_i as data_src4_0_, globalDataSrc.data_src_field_i as data_src5_0_, globalDataSrc.val_i as val_i0_, globalDataSrc.chg_by_i as chg_by_i0_, globalDataSrc.chg_on_d as chg_on_d0_ FROM GLOBAL_DATA_SRC_INSTANCE_TB globalDataSrc
WHERE globalDataSrc.DATA_SRC_I = ?
AND globalDataSrc.DATA_SRC_ID_I = ?
AND globalDataSrc.DATA_SRC_SECONDARY_ID_I = ?
AND globalDataSrc.DATA_SRC_FIELD_I = ?

Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] preparing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '23' to parameter: 1
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '9' to parameter: 4
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '0' to parameter: 3
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '381' to parameter: 2
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] processing result set
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done processing result set (0 rows)
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done closing: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] closing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] total objects hydrated: 0
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] initializing non-lazy collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] about to open: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] values nextval for UNIQUE_HIT_SEQUENCE
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] preparing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Sequence identifier generated: 18408
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done closing: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] closing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] generated identifier: 18408
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] saving [com.gs.aml.refs.model.GlobalDataSrcInstanceTB#18408]
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] SQL query:

SELECT {globalDataSrc.*} FROM GLOBAL_DATA_SRC_INSTANCE_TB {globalDataSrc}
WHERE {globalDataSrc}.DATA_SRC_I = :dataSrc
AND {globalDataSrc}.DATA_SRC_ID_I = :dataSrcId
AND {globalDataSrc}.DATA_SRC_SECONDARY_ID_I = :dataSrcSecondaryId
AND {globalDataSrc}.DATA_SRC_FIELD_I = :dataSrcFieldId

Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] flushing session
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushing entities and processing referenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Processing unreferenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Scheduling collection removes/(re)creates/updates
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 1 insertions, 0 updates, 0 deletions to 42 objects
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] SQL query:

SELECT {globalDelta.*} FROM GLOBAL_DELTA_TB {globalDelta} WHERE {globalDelta}.VAL_I = :valId

Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] flushing session
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushing entities and processing referenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Processing unreferenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Scheduling collection removes/(re)creates/updates
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 1 insertions, 0 updates, 0 deletions to 43 objects
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Dont need to execute flush
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] about to open: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0]

SELECT globalDelta.val_i as val_i0_, globalDelta.val_c as val_c0_, globalDelta.chg_by_i as chg_by_i0_, globalDelta.chg_on_d as chg_on_d0_ FROM GLOBAL_DELTA_TB globalDelta WHERE globalDelta.VAL_I = ?

Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] preparing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '18677' to parameter: 1
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] processing result set
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done processing result set (0 rows)
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done closing: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] closing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] total objects hydrated: 0
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] initializing non-lazy collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] generated identifier: 18677
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] saving [com.gs.aml.refs.model.GlobalDeltaTB#18677]
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] commit
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] flushing session
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushing entities and processing referenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Processing unreferenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Scheduling collection removes/(re)creates/updates
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 2 insertions, 0 updates, 0 deletions to 44 objects
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] listing entities:
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] insert into amlrefsdev.HISTORY_TB (val_i, val_c, data_src_i, data_src_id_i, data_src_secondary_id_i, data_src_field_i, unique_hit_id_i, iso_code_c, tier_i, comment_c, status_c, chg_by_i, list_type_i, chg_on_d) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] preparing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Dehydrating entity: [com.gs.aml.refs.model.HistoryTB#2004-09-15 17:31:00.533]
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '18677' to parameter: 1
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding 'GARCIA, DANIEL' to parameter: 2
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '23' to parameter: 3
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '381' to parameter: 4
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '0' to parameter: 5
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '9' to parameter: 6
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '18408' to parameter: 7
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding null to parameter: 8
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '0' to parameter: 9
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding 'Adding new entry in GlobalDataSrcInstanceTBTB' to parameter: 10
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding 'A' to parameter: 11
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '1' to parameter: 12
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '1' to parameter: 13
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '15 September 2004 17:31:00' to parameter: 14
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Inserting entity: [com.gs.aml.refs.model.GlobalDeltaTB#18677]
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done closing: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] closing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] about to open: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] insert into amlrefsdev.GLOBAL_DELTA_TB (val_c, chg_by_i, chg_on_d, val_i) values (?, ?, ?, ?)
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] preparing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Dehydrating entity: [com.gs.aml.refs.model.GlobalDeltaTB#18677]
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding 'GARCIA, DANIEL' to parameter: 1
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '1' to parameter: 2
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '15 September 2004 17:31:00' to parameter: 3
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '18677' to parameter: 4
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done closing: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] closing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] post flush
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] transaction completion
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Successfully inserted entity name data in Global TB
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] begin
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] current autocommit status:false
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] SQL query:

SELECT {entityMetaData.*} FROM GLOBAL_META_DATA_TB {entityMetaData}
WHERE {entityMetaData}.DATA_SRC_I = :dataSrc
AND {entityMetaData}.DATA_SRC_ID_I = :dataSrcId
AND {entityMetaData}.DATA_SRC_SECONDARY_ID_I = :dataSrcSecondaryId

Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] flushing session
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushing entities and processing referenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Processing unreferenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Scheduling collection removes/(re)creates/updates
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 0 insertions, 0 updates, 0 deletions to 44 objects
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] listing entities:
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Dont need to execute flush
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] about to open: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0]

SELECT entityMetaData.data_src_i as data_src_i0_, entityMetaData.data_src_id_i as data_src2_0_, entityMetaData.data_src_secondary_id_i as data_src3_0_, entityMetaData.meta_data_type_i as meta_dat4_0_, entityMetaData.meta_data_text_c as meta_dat5_0_, entityMetaData.chg_by_i as chg_by_i0_, entityMetaData.chg_on_dt as chg_on_dt0_ FROM GLOBAL_META_DATA_TB entityMetaData
WHERE entityMetaData.DATA_SRC_I = ?
AND entityMetaData.DATA_SRC_ID_I = ?
AND entityMetaData.DATA_SRC_SECONDARY_ID_I = ?

Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] preparing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '23' to parameter: 1
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '0' to parameter: 3
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '381' to parameter: 2
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] processing result set
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done processing result set (0 rows)
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done closing: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] closing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] total objects hydrated: 0
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] initializing non-lazy collectionsWed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] generated identifier: com.gs.aml.refs.model.GlobalMetaDataCompositeKey@1278eb
int...
int...
int...
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] saving [com.gs.aml.refs.model.GlobalMetaDataTB#com.gs.aml.refs.model.GlobalMetaDataCompositeKey@1278eb]
int...
int...
int...
int...
int...
int...
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] SQL query:

SELECT {entityMetaData.*} FROM GLOBAL_META_DATA_TB {entityMetaData}
WHERE {entityMetaData}.DATA_SRC_I = :dataSrc
AND {entityMetaData}.DATA_SRC_ID_I = :dataSrcId
AND {entityMetaData}.DATA_SRC_SECONDARY_ID_I = :dataSrcSecondaryId

Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] flushing session
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushing entities and processing referenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Processing unreferenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Scheduling collection removes/(re)creates/updates
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 1 insertions, 0 updates, 0 deletions to 45 objects
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] listing entities:
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] changes must be flushed to space: amlrefsdev.GLOBAL_META_DATA_TB
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Need to execute flush
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] executing flush
int...
int...
int...
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Inserting entity: [com.gs.aml.refs.model.GlobalMetaDataTB#com.gs.aml.refs.model.GlobalMetaDataCompositeKey@1278eb]
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] about to open: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] insert into amlrefsdev.GLOBAL_META_DATA_TB (meta_data_type_i, meta_data_text_c, chg_by_i, chg_on_dt, data_src_i, data_src_id_i, data_src_secondary_id_i) values (?, ?, ?, ?, ?, ?, ?)
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] preparing statement
int...
int...
int...
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Dehydrating entity: [com.gs.aml.refs.model.GlobalMetaDataTB#com.gs.aml.refs.model.GlobalMetaDataCompositeKey@1278eb]
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '1' to parameter: 1
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '<EntityInfo entityname="GARCIA, DANIEL" entitytype="I" entitytitle="" />' to parameter: 2
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '1' to parameter: 3
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '15 September 2004 17:31:00' to parameter: 4
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '23' to parameter: 5
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '381' to parameter: 6
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '0' to parameter: 7
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done closing: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] closing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] post flush
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] about to open: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0]

SELECT entityMetaData.data_src_i as data_src_i0_, entityMetaData.data_src_id_i as data_src2_0_, entityMetaData.data_src_secondary_id_i as data_src3_0_, entityMetaData.meta_data_type_i as meta_dat4_0_, entityMetaData.meta_data_text_c as meta_dat5_0_, entityMetaData.chg_by_i as chg_by_i0_, entityMetaData.chg_on_dt as chg_on_dt0_ FROM GLOBAL_META_DATA_TB entityMetaData
WHERE entityMetaData.DATA_SRC_I = ?
AND entityMetaData.DATA_SRC_ID_I = ?
AND entityMetaData.DATA_SRC_SECONDARY_ID_I = ?

Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] preparing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '23' to parameter: 1
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '0' to parameter: 3
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] binding '381' to parameter: 2
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] processing result set
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] returning '23' as column: data_src_i0_
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] returning '381' as column: data_src2_0_
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] returning '0' as column: data_src3_0_
int...
int...
int...
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] result row: com.gs.aml.refs.model.GlobalMetaDataCompositeKey@1278eb
int...
int...
int...
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done processing result set (1 rows)
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] done closing: 0 open PreparedStatements, 0 open ResultSets
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] closing statement
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] total objects hydrated: 0
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] initializing non-lazy collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] generated identifier: 2004-09-15 17:31:00.658
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] saving [com.gs.aml.refs.model.GlobalMetaDataHistoryTB#2004-09-15 17:31:00.658]
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] commit
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] flushing session
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushing entities and processing referenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Processing unreferenced collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Scheduling collection removes/(re)creates/updates
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 1 insertions, 0 updates, 0 deletions to 46 objects
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
Wed Sep 15 17:31:00 EDT 2004 DEBUG [Thread-0] listing entities:

Hibernate does not itself cache prepared statements. That is the job of the underlying connection pool.

Hi Gavin,

Thanks for the quick response.

Yes, but if we are creating the following object,

Query globalQuery= session.getNamedQueryREFSConstants.GLOBAL_SELECT_QUERY)

via Hibernate, does hibernate use c3p0's prepared statement caching?? If not, how can we cache them?? Does hibernate open and close a prepared statement each time we use the global query object??

Does hibernate consider the Query object a prepared Statement, thus allowing the underlying DBCP to cache it???

Thanks Again!!

Hello!!

I also noticed in the SessionImpl.java class the following:

** THAT THE SQLLoader loader is being instantiated each time and there is a note that they can be cached???

Does this confirm that the preparedStatements/Query object are NOT being cached???

Thanks.

public List findBySQL(String sqlQuery, String[] aliases, Class[] classes, QueryParameters queryParameters, Collection querySpaces) throws HibernateException {

if ( log.isTraceEnabled() ) log.trace( "SQL query: " + sqlQuery );

SQLLoadable persisters[] = new SQLLoadable[classes.length];
for (int i = 0; i < classes.length; i++) {
persisters[i] = getSQLLoadable( classes[i] );
}

//TODO: we could cache these!!
SQLLoader loader = new SQLLoader(aliases, persisters, factory, sqlQuery, querySpaces);

autoFlushIfRequired( loader.getQuerySpaces() );

dontFlushFromFind++;
try {
return loader.list(this, queryParameters);
}
catch (SQLException sqle) {
throw new JDBCException(sqle);
}
finally {
dontFlushFromFind--;
}
}

Hello!!

I also noticed in the SessionImpl.java class the following:

** THAT THE SQLLoader loader is being instantiated each time and there is a note that they can be cached???

Does this confirm that the preparedStatements/Query object are NOT being cached???

Thanks.

public List findBySQL(String sqlQuery, String[] aliases, Class[] classes, QueryParameters queryParameters, Collection querySpaces) throws HibernateException {

if ( log.isTraceEnabled() ) log.trace( "SQL query: " + sqlQuery );

SQLLoadable persisters[] = new SQLLoadable[classes.length];
for (int i = 0; i < classes.length; i++) {
persisters[i] = getSQLLoadable( classes[i] );
}

//TODO: we could cache these!!
SQLLoader loader = new SQLLoader(aliases, persisters, factory, sqlQuery, querySpaces);

autoFlushIfRequired( loader.getQuerySpaces() );

dontFlushFromFind++;
try {
return loader.list(this, queryParameters);
}
catch (SQLException sqle) {
throw new JDBCException(sqle);
}
finally {
dontFlushFromFind--;
}
}

Um. I'm trying to figure out: How was my statement above open to any kind of misinterpretation?

(1) Hibernate does not cache prepared statements
(2) The connection pool does (assuming it is configured to)

That answers your question, right?

I think that what gavin is trying to say is that the console output...

> done closing: 0 open PreparedStatements, 0 open ResultSets

only indicates that hibernate has not failed to close any PreparedStatements. JDBC PreparedStatement caching is the responsibility of the Connection pool, and design specifies that such caching be completely transparent to the client (hibernate in this case). hibernate has properly called close() on the PreparedStatements, and that's all that it's responsible for.

If you set hibernate.c3p0.max_statements (or c3p0.maxStatementsPerConnection in c3p0.properties in the latest c3p0), PreparedStatements will in fact be cached. hibernate just won't know a thing about it. And it will be hard for you to know it either, other than seeing improved performance (or diminished performance -- it depends on your database environment) in your application.

When c3p0 has more configurable logging -- soon, I promise -- I'll add some means for users to trace the state of the Connection pool, so you can be sure that yes, your Connections are in fact being cached. For now, "transparency Statement caching" means that Statement caching is like a tree falling in an empty forest... unless you benchmark to see the performance difference (or mess with the source to turn on tracing) it's a philosophical question whether it really happens. You can take my word that it does. Or, better yet, you really should benchmark with it on, and off, both to notice that there's a difference, and to know whether your configuration statement caching helps or hurts.

(Statement caching will help if your database does a significant amount of work parsing, planning, and optimizing a query at statement prepare time, and if it reuses that work for multiple calls to the prepared statement. Statement caching will usually hurt if a prepared statement implementation only retains the query in String for, and resends raw SQL to the database for each query. Different drivers implement PreparedStatements differently.)

smiles,
Steve (c3p0 guy)

p.s. there were some trackers for c3p0 on SourceForge that I didn't have myself set-up to receive notications on, and some support and feature requests, including one similar to this, posted up to 8 months ago that I never noticed... apologies to any and all who used those trackers, which should now provoke a more prompt response.