title: Hibernate takes too much time and performs some cryptic actions..
body: <p>I dont understand a lot of actions that hibernate performs.For eg:  TwoPhaseLoad,Loader,EntityPrinter etc...  Though I have added cp30 (connection pool) properties,  hibernate is opening/closing jdbc connection for each query..</p>
  
  <p>Also, could anyone suggest as to how to reduce the time for the queries. In this case, I am fetching just 7 objects and it takes almost 3 seconds... FYI I am not using any associations..</p>
  
  <pre><code> CP30 Props:
  &lt;prop key="hibernate.c3p0.min_size"&gt;5&lt;/prop&gt;
  &lt;prop key="hibernate.c3p0.max_size"&gt;20&lt;/prop&gt;
  &lt;prop key="hibernate.c3p0.timeout"&gt;300&lt;/prop&gt;
  &lt;prop key="hibernate.c3p0.max_statements"&gt;50&lt;/prop&gt;
   &lt;prop key="hibernate.c3p0.idle_test_period"&gt;3000&lt;/prop&gt;
  
  
      18:03:18,037 DEBUG LogicalConnectionImpl:212 - Obtaining JDBC connection
      18:03:18,048 DEBUG LogicalConnectionImpl:218 - Obtained JDBC connection
      18:03:18,056 DEBUG AbstractTransactionImpl:158 - begin
      18:03:18,056 DEBUG JdbcTransaction:69 - initial autocommit status: true
      18:03:18,057 DEBUG JdbcTransaction:71 - disabling autocommit
      18:03:18,135 DEBUG QueryTranslatorImpl:265 - parse() - HQL: from XXX
      18:03:18,146 DEBUG QueryTranslatorImpl:283 - --- HQL AST ---
       \-[QUERY] Node: 'query'
          \-[SELECT_FROM] Node: 'SELECT_FROM'
             \-[FROM] Node: 'from'
                \-[RANGE] Node: 'RANGE'
                   \-[DOT] Node: '.'
                      +-[DOT] Node: '.'
                      |  +-[DOT] Node: '.'
                      |  |  +-[DOT] Node: '.'
                      |  |  |  +-[IDENT] Node: 'XXX'
                      |  |  |  \-[IDENT] Node: 'XXX'
                      |  |  \-[IDENT] Node: 'XXX'
                      |  \-[IDENT] Node: 'XXX'
                      \-[IDENT] Node: 'XXX'
  
      18:03:18,146 DEBUG ErrorCounter:82 - throwQueryException() : no errors
      18:03:18,181 DEBUG HqlSqlBaseWalker:121 - select &lt;&lt; begin [level=1, statement=select]
      18:03:18,205 DEBUG FromElement:157 - FromClause{level=1} : XXX (&lt;no alias&gt;) -&gt; region0_
      18:03:18,205 DEBUG HqlSqlBaseWalker:125 - select : finishing up [level=1, statement=select]
      18:03:18,206 DEBUG HqlSqlWalker:629 - processQuery() :  ( SELECT ( FromClause{level=1} CRMMAINT.dbo.Region region0_ ) )
      18:03:18,212 DEBUG HqlSqlWalker:869 - Derived SELECT clause created.
      18:03:18,221 DEBUG JoinProcessor:175 - Using FROM fragment [CRMMAINT.dbo.Region region0_]
      18:03:18,222 DEBUG HqlSqlBaseWalker:129 - select &gt;&gt; end [level=1, statement=select]
      18:03:18,223 DEBUG QueryTranslatorImpl:252 - --- SQL AST ---
       \-[SELECT] QueryNode: 'SELECT'  querySpaces (CRMMAINT.dbo.Region)
          +-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
          |  +-[SELECT_EXPR] SelectExpressionImpl: 'region0_.Region as Region1_12_, region0_.Country as Country2_12_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=CRMMAINT.dbo.Region,tableAlias=region0_,origin=null,columns={,className=XXX}}}
          |  \-[SQL_TOKEN] SqlFragment: 'region0_.Description as Descript3_12_, region0_.Display as Display4_12_'
          \-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[], fromElementByTableAlias=[region0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
             \-[FROM_FRAGMENT] FromElement: 'CRMMAINT.dbo.Region region0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=CRMMAINT.dbo.Region,tableAlias=region0_,origin=null,columns={,className=XXX}}
  
      18:03:18,224 DEBUG ErrorCounter:82 - throwQueryException() : no errors
      18:03:18,234 DEBUG QueryTranslatorImpl:235 - HQL: from XXX
      18:03:18,234 DEBUG QueryTranslatorImpl:236 - SQL: select region0_.Region as Region1_12_, region0_.Country as Country2_12_, region0_.Description as Descript3_12_, region0_.Display as Display4_12_ from CRMMAINT.dbo.Region region0_
      18:03:18,235 DEBUG ErrorCounter:82 - throwQueryException() : no errors
      18:03:18,319 DEBUG SQL:104 - select region0_.Region as Region1_12_, region0_.Country as Country2_12_, region0_.Description as Descript3_12_, region0_.Display as Display4_12_ from CRMMAINT.dbo.Region region0_
      18:03:18,333 DEBUG Loader:941 - Result set row: 0
      18:03:18,339 DEBUG Loader:1475 - Result row: EntityKey[XXX#component[region,country]{region=CANADA, country=Canada}]
      18:03:18,348 DEBUG Loader:941 - Result set row: 1
      18:03:18,349 DEBUG Loader:1475 - Result row: EntityKey[XXX#component[region,country]{region=US-CAN OPS, country=United States}]
      18:03:18,350 DEBUG Loader:941 - Result set row: 2
      18:03:18,350 DEBUG Loader:1475 - Result row: EntityKey[XXX#component[region,country]{region=US1 - NORTH WEST, country=United States}]
      18:03:18,351 DEBUG Loader:941 - Result set row: 3
      18:03:18,352 DEBUG Loader:1475 - Result row: EntityKey[XXX#component[region,country]{region=US2 - GULF PLAINS, country=United States}]
      18:03:18,352 DEBUG Loader:941 - Result set row: 4
      18:03:18,353 DEBUG Loader:1475 - Result row: EntityKey[XXX#component[region,country]{region=US3 - MID CENTRAL, country=United States}]
      18:03:18,354 DEBUG Loader:941 - Result set row: 5
      18:03:18,354 DEBUG Loader:1475 - Result row: EntityKey[XXX#component[region,country]{region=US4 - SOUTH EAST, country=United States}]
      18:03:18,355 DEBUG Loader:941 - Result set row: 6
      18:03:18,356 DEBUG Loader:1475 - Result row: EntityKey[XXX#component[region,country]{region=US5 - NORTH EAST, country=United States}]
      18:03:18,358 DEBUG TwoPhaseLoad:158 - Resolving associations for [XXX#component[region,country]{region=CANADA, country=Canada}]
      18:03:18,361 DEBUG TwoPhaseLoad:277 - Done materializing entity [XXX#component[region,country]{region=CANADA, country=Canada}]
      18:03:18,363 DEBUG TwoPhaseLoad:158 - Resolving associations for [XXX#component[region,country]{region=US-CAN OPS, country=United States}]
      18:03:18,363 DEBUG TwoPhaseLoad:277 - Done materializing entity [XXX#component[region,country]{region=US-CAN OPS, country=United States}]
      18:03:18,364 DEBUG TwoPhaseLoad:158 - Resolving associations for [XXX#component[region,country]{region=US1 - NORTH WEST, country=United States}]
      18:03:18,364 DEBUG TwoPhaseLoad:277 - Done materializing entity [XXX#component[region,country]{region=US1 - NORTH WEST, country=United States}]
      18:03:18,365 DEBUG TwoPhaseLoad:158 - Resolving associations for [XXX#component[region,country]{region=US2 - GULF PLAINS, country=United States}]
      18:03:18,366 DEBUG TwoPhaseLoad:277 - Done materializing entity [XXX#component[region,country]{region=US2 - GULF PLAINS, country=United States}]
      18:03:18,366 DEBUG TwoPhaseLoad:158 - Resolving associations for [XXX#component[region,country]{region=US3 - MID CENTRAL, country=United States}]
      18:03:18,367 DEBUG TwoPhaseLoad:277 - Done materializing entity [XXX#component[region,country]{region=US3 - MID CENTRAL, country=United States}]
      18:03:18,367 DEBUG TwoPhaseLoad:158 - Resolving associations for [XXX#component[region,country]{region=US4 - SOUTH EAST, country=United States}]
      18:03:18,375 DEBUG TwoPhaseLoad:277 - Done materializing entity [XXX#component[region,country]{region=US4 - SOUTH EAST, country=United States}]
      18:03:18,376 DEBUG TwoPhaseLoad:158 - Resolving associations for [XXX#component[region,country]{region=US5 - NORTH EAST, country=United States}]
      18:03:18,377 DEBUG TwoPhaseLoad:277 - Done materializing entity [XXX#component[region,country]{region=US5 - NORTH EAST, country=United States}]
      18:03:18,381 DEBUG ConcurrentStatisticsImpl:411 - HHH000117: HQL: from Region, time: 71ms, rows: 7
      18:03:18,384 DEBUG AbstractTransactionImpl:173 - committing
      18:03:18,385 DEBUG AbstractFlushingEventListener:143 - Processing flush-time cascades
      18:03:18,389 DEBUG AbstractFlushingEventListener:184 - Dirty checking collections
      18:03:18,393 DEBUG AbstractFlushingEventListener:117 - Flushed: 0 insertions, 0 updates, 0 deletions to 7 objects
      18:03:18,394 DEBUG AbstractFlushingEventListener:124 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
      18:03:18,396 DEBUG EntityPrinter:114 - Listing entities:
      18:03:18,415 DEBUG EntityPrinter:121 - XXX{id=component[region,country]{region=US2 - GULF PLAINS, country=United States}, description=Gulf Plains, display=1}
      18:03:18,415 DEBUG EntityPrinter:121 - XXX{id=component[region,country]{region=US5 - NORTH EAST, country=United States}, description=North East, display=1}
      18:03:18,416 DEBUG EntityPrinter:121 - XXX{id=component[region,country]{region=CANADA, country=Canada}, description=Canada, display=1}
      18:03:18,416 DEBUG EntityPrinter:121 - XXX{id=component[region,country]{region=US3 - MID CENTRAL, country=United States}, description=Mid Central, display=1}
      18:03:18,417 DEBUG EntityPrinter:121 - XXX{id=component[region,country]{region=US4 - SOUTH EAST, country=United States}, description=South East, display=1}
      18:03:18,417 DEBUG EntityPrinter:121 - XXX{id=component[region,country]{region=US-CAN OPS, country=United States}, description=US-CAN OPS, display=1}
      18:03:18,417 DEBUG EntityPrinter:121 - XXX{id=component[region,country]{region=US1 - NORTH WEST, country=United States}, description=North West, display=1}
      18:03:18,418 DEBUG JdbcTransaction:113 - committed JDBC Connection
      18:03:18,418 DEBUG JdbcTransaction:126 - re-enabling autocommit
      18:03:18,420 DEBUG LogicalConnectionImpl:232 - Releasing JDBC connection
      18:03:18,421 DEBUG LogicalConnectionImpl:250 - Released JDBC connection
  18:03:20,424 DEBUG LogicalConnectionImpl:212 - Obtaining JDBC connection
  18:03:20,432 DEBUG LogicalConnectionImpl:218 - Obtained JDBC connection
  18:03:20,433 DEBUG AbstractTransactionImpl:158 - begin
  18:03:20,433 DEBUG JdbcTransaction:69 - initial autocommit status: true
  18:03:20,434 DEBUG JdbcTransaction:71 - disabling autocommit
  18:03:20,449 DEBUG QueryTranslatorImpl:265 - parse() - HQL: SELECT l FROM Location l WHERE l.region = :region
  </code></pre>