Hibernate 花费太多时间并执行一些神秘的操作..

Question

我不明白 hibernate 执行的很多操作。例如:TwoPhaseLoad、Loader、EntityPrinter 等...虽然我添加了 cp30(连接池)属性，但 hibernate 正在为每个查询打开/关闭 jdbc 连接..

此外，任何人都可以建议如何减少查询时间。在这种情况下，我只获取了 7 个对象，它花费了将近 3 秒......仅供引用，我没有使用任何关联......

 CP30 Props:
<prop key="hibernate.c3p0.min_size">5</prop>
<prop key="hibernate.c3p0.max_size">20</prop>
<prop key="hibernate.c3p0.timeout">300</prop>
<prop key="hibernate.c3p0.max_statements">50</prop>
 <prop key="hibernate.c3p0.idle_test_period">3000</prop>


    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 << begin [level=1, statement=select]
    18:03:18,205 DEBUG FromElement:157 - FromClause{level=1} : XXX (<no alias>) -> 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 >> 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

Answer 1

您已激活调试信息；尝试禁用 Turning off hibernate logging console output并检查您的查询是否运行得更快；通常控制台输出是性能的 killer 。