1. 首页
  2. 问答
  3. Hibernate的事务管理器性能问题

Hibernate的事务管理器性能问题

2015-10-13 72 views
3

我目前遇到性能问题在Hibernate中Hibernate的事务管理器性能问题

执行SQL语句（如SELECT * FROM表），大约需要90毫秒与12列

获取仅10个记录。然而，对于休眠运行在DAO类下面的Java代码

List<T> afterGetAll = getSessionFactory().getCurrentSession().createCriteria(type).list();

大约需要260〜300毫秒以上语句只执行完成，更不用说额外的执行时间我调用该DAO的服务类。共花费约600〜1000毫秒。我怀疑大部分时间都花在了事务管理上。

我不知道在我的代码/配置出了问题，我也曾尝试以下方法，但并不能帮助太多...

  1. 添加的数据源连接池设置
  2. 使用Hibernate本地SQL方法，而不是个createCriteria在DAO类
  3. 启用延迟加载
  4. Tomcat服务器的增加堆大小
  5. 使用二级缓存提供
  6. @Transactional（readOnly的=真）对于只读查询

一些解决方法用于加速操作：

  1. 通过配置EhCacheRegionFactory启用休眠缓存和一起使第二级缓存。然后在服务器启动时，我的Web应用程序通过手动触发服务调用来初始化缓存。在将Hibernate的sql查询从300〜400ms提取到1〜3ms后，这可以成功地减少到Java类的数据绑定过程。然而，瓶颈是在将事务的点...（见更新＃低于2）

这里是我的配置和代码

Hibernate配置

<bean id="jdbcTemplate" class="com.mchange.v2.c3p0.ComboPooledDataSource"> 
    <property name="driverClass" value="com.mysql.jdbc.Driver" /> 
    <property name="jdbcUrl" value="jdbc:mysql://test /> 
    <property name="user" value="test" /> 
    <property name="password" value="test" /> 
    <property name="maxPoolSize" value="20" /> 
    <property name="minPoolSize" value="5" /> 
    <property name="maxStatements" value="5" /> 
</bean> 

<bean id="sessionFactory" class="org.springframework.orm.hibernate4.LocalSessionFactoryBean"> 
    <property name="dataSource" ref="jdbcTemplate"></property> 
    <property name="mappingResources"> 
     <list> 
      <value>orm/UserModel.hbm.xml</value> 
      <value>orm/UserToken.hbm.xml</value> 
      <value>orm/RoleModel.hbm.xml</value> 
     </list> 
    </property> 
    <property name="hibernateProperties"> 
     <props> 
     <prop key="hibernate.dialect">org.hibernate.dialect.MySQL5Dialect</prop> 
     <prop key="hibernate.show_sql">true</prop> 
     <prop key="hibernate.format_sql">true</prop> 
     <prop key="hibernate.use_sql_comments">true</prop> 
     <prop key="hibernate.enable_lazy_load_no_trans">true</prop> 
     <prop key="hibernate.cache.provider_class">org.hibernate.cache.EhCacheProvider</prop> 
     <prop key="hibernate.cache.use_second_level_cache">true</prop> 
     <prop key="hibernate.c3p0.minPoolSize">5</prop> 
     <prop key="hibernate.c3p0.maxPoolSize">20</prop> 
     </props> 
    </property> 
</bean> 

<bean id="baseDao" abstract="true" class="com.test.app.project.dao.BaseDAOImpl"> 
    <property name="sessionFactory" ref="sessionFactory" /> 
</bean> 

<bean id="userDao" parent="baseDao" class="com.test.app.project.dao.UserDAOImpl"> 
</bean> 

<bean id="userService" class="com.test.app.project.services.UserServiceImpl"> 
    <property name="userDao" ref="userDao" /> 
</bean> 

<bean id="transactionManager" class="org.springframework.orm.hibernate4.HibernateTransactionManager"> 
    <property name="sessionFactory" ref="sessionFactory" /> 
</bean>

DAO类中的所有方法

public <T> List<T> getAll(final Class<T> type) { 
     long startTime = System.nanoTime(); 
     List<T> afterGetAll = getSessionFactory().getCurrentSession().createSQLQuery("SELECT user_id,username,email,is_active FROM app_users") 
       .addScalar("user_id", LongType.INSTANCE) 
       .addScalar("username", StringType.INSTANCE) 
       .addScalar("email", StringType.INSTANCE) 
       .addScalar("is_active", IntegerType.INSTANCE) 
       .setResultTransformer(Transformers.aliasToBean(UserModel.class)).list(); 
     //List<T> afterGetAll = getSessionFactory().getCurrentSession().createCriteria(type).list(); 
     long endTime = System.nanoTime(); 
     long duration = (endTime - startTime); 
     logger.info("============getAll=============== Execution Timestamp: " + duration/1000000 + "milliseconds"); 
     return afterGetAll; 
    }

服务类调用上述DAO

@Transactional(propagation=Propagation.REQUIRES_NEW,isolation = Isolation.READ_COMMITTED) 
@Service 
public class UserServiceImpl implements UserService{ 
... 
    @Override 
    public <T> List<T> getAll(Class<T> type) { 
     List<T> userList = userDao.getAll(type); 
     return userList; 
    } 
... 
}

任何建议在配置/代码可以提高性能也受到欢迎。由于第一

更新＃1： 启用休眠的统计数据后，我可以推断大多数的时间，由于以下统计数据花费不上执行的语句。

2015-10-14 10:45:46 INFO StatisticalLoggingSessionEventListener:275 - Session M 
etrics { 
    298847 nanoseconds spent acquiring 1 JDBC connections; 
    0 nanoseconds spent releasing 0 JDBC connections; 
    914957 nanoseconds spent preparing 1 JDBC statements; 
    335661830 nanoseconds spent executing 1 JDBC statements; 
    0 nanoseconds spent executing 0 JDBC batches; 
    0 nanoseconds spent performing 0 L2C puts; 
    0 nanoseconds spent performing 0 L2C hits; 
    0 nanoseconds spent performing 0 L2C misses; 
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 
0 collections); 
    5735 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 en 
tities and 0 collections) 
} 

2015-10-14 10:45:46 INFO AdminOperationController:51 - =======/admin/operation/ 
UserManagement Execution Timestamp:====== 3051milliseconds

事实证明，执行时间是在执行控制器类调用该服务之间不同的近10倍仅调用DAO和休眠

更新＃2

我执行的语句尝试添加一些毫秒时间戳来追踪大部分时间花费哪个进程。后来，我发现大部分时间都是在每次服务操作之后将hibernate事务公开为jdbc事务和提交事务。统计发现日志如下

2015-10-15 18:00:13,768 DEBUG HibernateTransactionManager:448 - Preparing JDBC Connection of Hibernate Session [SessionImpl(PersistenceContext[entityKeys=[],collectionKeys=[]];ActionQueue[insertions=o[email protected] [email protected] [email protected] [email protected] [email protected]223d [email protected]c1 [email protected]11 [email protected]4c33 unresolvedInsertDependencies=UnresolvedEntityInsertActions[]])] 
2015-10-15 18:00:13,847 DEBUG HibernateTransactionManager:516 - Exposing Hibernate transaction as JDBC transaction [ConnectionHandle{url=jdbc:mysql://test, user=test, debugHandle=null, lastResetAgoInSec=18, lastUsedAgoInSec=18, creationTimeAgoInSec=18}] 
2015-10-15 18:00:13,924 DEBUG SQL:109 - 
    /* dynamic native SQL query */ SELECT 
     user_id, 
     username, 
     email, 
     is_active 
    FROM 
     app_users 
2015-10-15 18:00:14,018 TRACE BasicExtractor:78 - extracted value ([user_id] : [BIGINT]) - [43] 
... 
... 
2015-10-15 18:00:14,177 TRACE BasicExtractor:78 - extracted value ([username] : [VARCHAR]) - [username33] 
2015-10-15 18:00:14,178 TRACE BasicExtractor:78 - extracted value ([email] : [VARCHAR]) - [[email protected]] 
2015-10-15 18:00:14,178 TRACE BasicExtractor:78 - extracted value ([is_active] : [INTEGER]) - [0] 
2015-10-15 18:00:14,178 TRACE BasicExtractor:78 - extracted value ([user_id] : [BIGINT]) - [136] 
2015-10-15 18:00:14,179 TRACE BasicExtractor:78 - extracted value ([username] : [VARCHAR]) - [username34] 
2015-10-15 18:00:14,179 TRACE BasicExtractor:78 - extracted value ([email] : [VARCHAR]) - [[email protected]] 
2015-10-15 18:00:14,180 TRACE BasicExtractor:78 - extracted value ([is_active] : [INTEGER]) - [0] 
2015-10-15 18:00:14,283 INFO BaseDAOImpl:117 - ============getAll=============== Execution Timestamp: 433milliseconds 
2015-10-15 18:00:14,284 DEBUG HibernateTransactionManager:759 - Initiating transaction commit 
2015-10-15 18:00:14,286 DEBUG HibernateTransactionManager:580 - Committing Hibernate transaction on Session [SessionImpl(PersistenceContext[entityKeys=[],collectionKeys=[]];ActionQueue[[email protected] [email protected] [email protected] [email protected] [email protected]223d [email protected]c1 [email protected]11 [email protected]4c33 unresolvedInsertDependencies=UnresolvedEntityInsertActions[]])] 
2015-10-15 18:00:14,496 DEBUG HibernateTransactionManager:669 - Closing Hibernate Session [SessionImpl(PersistenceContext[entityKeys=[],collectionKeys=[]];ActionQueue[[email protected] [email protected] [email protected] [email protected] [email protected]223d [email protected]c1 [email protected]11 [email protected]4c33 unresolvedInsertDependencies=UnresolvedEntityInsertActions[]])] after transaction 
2015-10-15 18:00:14,499 INFO StatisticalLoggingSessionEventListener:275 - Session Metrics { 
    21735 nanoseconds spent acquiring 1 JDBC connections; 
    0 nanoseconds spent releasing 0 JDBC connections; 
    10155810 nanoseconds spent preparing 1 JDBC statements; 
    69653167 nanoseconds spent executing 1 JDBC statements; 
    0 nanoseconds spent executing 0 JDBC batches; 
    11795265 nanoseconds spent performing 1 L2C puts; 
    0 nanoseconds spent performing 0 L2C hits; 
    69732 nanoseconds spent performing 1 L2C misses; 
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections); 
    31394 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections) 
} 
2015-10-15 18:00:14,639 INFO AdminOperationController:49 - =======/admin/operation/UserManagement Execution Timestamp:====== 924milliseconds

列出了初始化缓存

2015-10-15 18:00:22,410 DEBUG HibernateTransactionManager:516 - Exposing Hibernate transaction as JDBC transaction [ConnectionHandle{url=jdbc:mysql://test, user=test, debugHandle=null, lastResetAgoInSec=22, lastUsedAgoInSec=22, creationTimeAgoInSec=22}] 
2015-10-15 18:00:22,417 INFO BaseDAOImpl:117 - ============getAll=============== Execution Timestamp: 4milliseconds 
2015-10-15 18:00:22,418 DEBUG HibernateTransactionManager:759 - Initiating transaction commit 
2015-10-15 18:00:22,419 DEBUG HibernateTransactionManager:580 - Committing Hibernate transaction on Session [SessionImpl(PersistenceContext[entityKeys=[],collectionKeys=[]];ActionQueue[[email protected] [email protected] [email protected] [email protected] [email protected]39b0 [email protected]94 [email protected]4 [email protected]2ad8 unresolvedInsertDependencies=UnresolvedEntityInsertActions[]])] 
2015-10-15 18:00:22,625 DEBUG HibernateTransactionManager:669 - Closing Hibernate Session [SessionImpl(PersistenceContext[entityKeys=[],collectionKeys=[]];ActionQueue[[email protected] [email protected] [email protected] [email protected] [email protected]39b0 [email protected]94 [email protected]4 [email protected]2ad8 unresolvedInsertDependencies=UnresolvedEntityInsertActions[]])] after transaction 
2015-10-15 18:00:22,627 INFO StatisticalLoggingSessionEventListener:275 - Session Metrics { 
    19621 nanoseconds spent acquiring 1 JDBC connections; 
    0 nanoseconds spent releasing 0 JDBC connections; 
    0 nanoseconds spent preparing 0 JDBC statements; 
    0 nanoseconds spent executing 0 JDBC statements; 
    0 nanoseconds spent executing 0 JDBC batches; 
    0 nanoseconds spent performing 0 L2C puts; 
    2170444 nanoseconds spent performing 1 L2C hits; 
    0 nanoseconds spent performing 0 L2C misses; 
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections); 
    19018 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections) 
} 
2015-10-15 18:00:22,766 INFO AdminOperationController:49 - =======/admin/operation/UserManagement Execution Timestamp:====== 425milliseconds

有谁可以建议我应该如何改善这种情况呢？

来源

2015-10-13 SerMintt

+0

您是否尝试过设置@Transactional（readOnly = true）以上公开列表 getAll（类别类型）？ –

+0

你的setResultTransformer调用真的是强制性的吗？通用方法呢？ （可以将ResultTransformer应用于本机SQL查询，例如，这允许返回非管理实体）。 –

+0

@AndréBlaszczyk 我也尝试了@Transactional（readOnly = true）对于那些只读查询，但没有运气 setResultTransformer调用不是必需的，只是一些实验。我原来的代码是在下面评论的代码...但是在性能方面没有太大的区别。 – SerMintt

回答

0

终于解决了这个问题。 除了配置解决方案（请参阅我编辑的文章，我使用缓存初始化），我重构我的代码尽可能在一个事务服务方法中进行适当的DAO操作（在此之前，我的事务服务只有非常简化的方法，即我可能需要调用几个交易服务方法一个工作流程（如注册新用户），这是非常昂贵的这样做。

它提高我的表现更进一步。

正如我们看到的，在我的帖子更新＃2 ，瓶颈是交易提交，可能是数据库服务器问题，现在我把db改成localhost，速度从400〜500ms进一步提升到20ms

来源

2015-10-15 15:26:53 SerMintt

2

请找一些建议：

  1. 设置hibernate.show_sql为“假”，确保Hibernate日志是在可能的最低记录水平运行。
  2. 定义为延迟加载作为首选关联加载策略。
  3. 设置@Transactional（readOnly = true）关于查询和标准，当返回的对象将永远不会被修改。
  4. 大多数查询不会从缓存中受益，所以默认情况下查询不会被缓存。要启用缓存，请致电Query.setCacheable（true）。
  5. 您可以激活Hibernate统计信息来分析性能问题（属性hibernate.generate_statistics设置为true）。
  6. 确认您在桌上有索引。

来源

2015-10-13 18:29:41

+0

谢谢。我试图激活Hibernate Statistics。这似乎是由于交易管理器问题（在我的文章中更新） – SerMintt

相关问题

 相关问题