Java MySQL Hibernate 慢速选择查询答案

【问题标题】：Java MySQL Hibernate slow select queriesJava MySQL Hibernate 慢速选择查询
【发布时间】：2012-03-30 05:01:23
【问题描述】：

我有一个用于持久化一些 Java 对象的 MySQL 表，并使用 Hibernate 来映射数据/列。对象/表包含大约 50 个列/字段。从表面上看，在最小负载下这工作正常，但我在启动程序时遇到了问题，我从表中加载所有可用对象。表中当前大约有 8500 行。这些行的加载需要很长时间，超过 5 分钟！显然这是不对的，我必须在我的 Hibernate 配置（或其他地方）中做错了什么。使用 java.sql.* 包对所有行进行正常查询大约需要 300 毫秒来检索 8000+ 行，这是可以接受的，但理想情况下，我希望保留 Hibernate 的映射功能。

我在下面附上了 Hibernate 的主要配置。我很高兴提供进一步的配置/实现细节，但我不想在这个阶段用什么可能是不必要的信息来夸大这个问题。

<hibernate-configuration>
<session-factory>
  <property name="hibernate.connection.driver_class">
    com.mysql.jdbc.Driver</property>
  <property name="hibernate.connection.url">

jdbc:mysql://127.0.0.1:3306/abc</property>
  <property name="hibernate.connection.username">user</property>
  <property name="hibernate.connection.password">password</property>

  <property name="org.hibernate.SQL">true</property>
  <property name="dialect">org.hibernate.dialect.MySQLDialect</property>
  <property name="hibernate.hbm2ddl.auto">update</property>

  <property name="hibernate.c3p0.idle_test_period">60</property>
  <property name="hibernate.c3p0.min_size">5</property>
  <property name="hibernate.c3p0.max_size">20</property>
  <property name="hibernate.c3p0.max_statements">250</property>
  <property name="hibernate.c3p0.timeout">1800</property>
  <property name="hibernate.c3p0.acquireRetryAttempts">1</property>
  <property name="hibernate.c3p0.acquireRetryDelay">250</property>

  <property name= "hibernate.transaction.factory_class">
      org.hibernate.transaction.JDBCTransactionFactory
  </property>
  <property name="hibernate.current_session_context_class">thread</property>

我最初使用默认连接池，但尝试切换到 C3P0 希望它会有所帮助，但无论池如何，行的加载时间基本相同。

显然，我不是 Hibernate 专家，所以我真的很感激能了解我做错了什么。谢谢。

更新1 添加查询的日志输出。

20:16:40,633 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: 'com'
        |           |  |  |  \-[IDENT] Node: 'xyz'
        |           |  |  \-[IDENT] Node: 'objects'
        |           |  \-[IDENT] Node: 'abc'
        |           \-[IDENT] Node: 'ObjectID'
        \-[WHERE] Node: 'where'
           \-[EQ] Node: '='
              +-[IDENT] Node: 'event_id'
              \-[NUM_INT] Node: '1331570489282'

20:16:40,633 DEBUG QueryTranslatorImpl:252 - --- SQL AST ---
 \-[SELECT] QueryNode: 'SELECT'  querySpaces (order_log)
    +-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
    |  +-[SELECT_EXPR] SelectExpressionImpl: 'objectid0_.event_id as abc1_0_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=order_log,tableAlias=objectid0_,origin=null,columns={,className=com.xyz.objects.abc.objectid}}}
    |  \-[SQL_TOKEN] SqlFragment: 'objectid0_.order_id as abc2_0_, objectid0_.order_id as order3_0_, objectid0_.px_cond as px4_0_, objectid0_.px_curr as px5_0_, objectid0_.px_value as px6_0_, objectid0_.vol_cond as vol7_0_, objectid0_.vol as vol0_, objectid0_.side as side0_, objectid0_.trd_vol as trd10_0_, objectid0_.open_vol as open11_0_, objectid0_.accno as accno0_, objectid0_.symbol as symbol0_, objectid0_.market as market0_, objectid0_.validity_type as validity15_0_, objectid0_.validity_date as validity16_0_, objectid0_.mod_date as mod17_0_, objectid0_.result_code as result18_0_, objectid0_.order_state as order19_0_, objectid0_.action_state as action20_0_, objectid0_.action_type as action21_0_, objectid0_.action_status as action22_0_, objectid0_.status_text as status23_0_, objectid0_.strategy_id as strategy24_0_, objectid0_.passive as passive0_, objectid0_.timestamp as timestamp0_, objectid0_.confirmedorder as confirm27_0_, objectid0_.updatesource as updates28_0_'
    +-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[], fromElementByTableAlias=[objectid0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
    |  \-[FROM_FRAGMENT] FromElement: 'order_log objectid0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=order_log,tableAlias=objectid0_,origin=null,columns={,className=com.abc.objects.xyz.objectid}}
    \-[WHERE] SqlNode: 'where'
       \-[EQ] BinaryLogicOperatorNode: '='
          +-[IDENT] IdentNode: 'event_id' {originalText=event_id}
          \-[NUM_INT] LiteralNode: '1331570489282'

日志中有更多的输出，但我认为上面的 2 项是最相关的。如果我错过了任何重要的事情，请告诉我。

UPDATE2 添加实际的 sql 输出。

Hibernate: /* from objectid where abc_event_id=1331570505614 */ select objectid0
_.abc_event_id as abc1_0_, objectid0_.abc_order_id as abc2_0_, objectid0_.
order_id as order3_0_, objectid0_.px_cond as px4_0_, objectid0_.px_curr as px5_0_,
 objectid0_.px_value as px6_0_, objectid0_.vol_cond as vol7_0_, objectid0_.vol as v
ol0_, objectid0_.side as side0_, objectid0_.trd_vol as trd10_0_, objectid0_.open_vo
l as open11_0_, objectid0_.accno as accno0_, objectid0_.symbol as symbol0_, ucorde
r0_.market as market0_, objectid0_.validity_type as validity15_0_, objectid0_.vali
dity_date as validity16_0_, objectid0_.mod_date as mod17_0_, objectid0_.result_cod
e as result18_0_, objectid0_.order_state as order19_0_, objectid0_.action_state as
 action20_0_, objectid0_.action_type as action21_0_, objectid0_.action_status as a
ction22_0_, objectid0_.status_text as status23_0_, objectid0_.strategy_id as strat
egy24_0_, objectid0_.passive as passive0_, objectid0_.timestamp as timestamp0_, uc
order0_.confirmedorder as confirm27_0_, objectid0_.updatesource as updates28_0_ f
rom order_log objectid0_ where abc_event_id=1331570505614

UPDATE 3对象映射+事务代码

<hibernate-mapping>
  <class name="com.abc.objects.xyz.objectid" table="order_log">
   <id name="EventId" type="long" column="event_id" >
   <generator class="assigned"/>
  </id>

  <property name="ordId">
    <column name="order_id"/>
  </property>
  <property name="pxCond">
    <column name="px_cond"/>
  </property>
...
</hibernate-mapping>

映射是一个摘录，但它与上述相同。查询该表的事务如下所示：

Session session = HibernateUtil.getSessionFactory().openSession();
org.hibernate.Transaction transaction = null;
try {
   long t0 = System.currentTimeMillis();
   transaction = session.beginTransaction();
   List<UCOrder> result = session.createQuery("from UCOrder").list();
   transaction.commit();
   System.out.println (result.size() + " rows were retrieved");
   System.out.println("Time elapsed: " + (System.currentTimeMillis()-t0));
} catch (Exception e) {
   transaction.rollback();
   e.printStackTrace();
} finally {
   session.close();
}

我想也相当直截了当？！？。但是，检索数据所花费的时间是下面所示的普通java.sql.* 方法的千倍：

Connection conn = DriverManager.getConnection (url, userName, password);
Statement s = conn.createStatement ();
s.executeQuery ("SELECT * FROM order_log");
ResultSet rs = s.getResultSet ();

【问题讨论】：

Hibernate 配置本身看起来都很好。您能否显示实际执行查询的 Hibernate 代码？正如 jabal 所说，hibernate.show_sql 也是一个好主意。
谢谢。我在上面添加了一些日志输出。
HQL AST 对我来说有点太多了，无法发现任何问题 ;) 请发布 Hibernate 生成的相关 SQL 查询，使用 hibernate.show_sql=true 和 hibernate.format_sql=true 记录它们。
@tscho 完成。 sql 查询对我来说并不陌生。
查询看起来没问题，但是这个查询检索了多少行？您能否也发布休眠映射和实际加载 8k+ 行需要很长时间的代码。

标签： java mysql hibernate configuration

【解决方案1】：

我建议您在 Hibernate 中打开详细日志记录。你可以让它记录所有的 SQL 查询，看看它们是否有异常。

执行此操作的一种方法是将hibernate.show_sql 设置为true 和/或（？）配置Hibernate 使用的commons-logging 以将所有org.hibernate 类别输出到您喜欢的输出文件。

【讨论】：

谢谢。我已经为org.hibernate=ALL 设置了 log4j 设置，这给了我很多输出。其中大部分对我来说是希腊语，但我注意到它指定了所有字段（即SELECT field1, field2,...，而不是使用通配符选择（*）。我不知道我是否可以更改它或者它是否会有所作为.
并非如此。将 (*) 解析为字段名称是我猜数据库首先要做的事情之一。 Hibernate 生成的 SQL 不太好读，但性能问题的答案应该隐藏在那里。
也许您可以复制查询并使用 MySQL 工具对其进行分析以找到瓶颈。
谢谢。我确实使用 Workbench 分析了 MySQL 服务器上的查询（参见上面的评论），实际查询以毫秒为单位执行。在我看来，有一些预处理和可能的后处理会消耗时间。我不知道是什么或为什么。
在这种情况下，我通常将 VisualVM (visualvm.java.net) 附加到我正在运行的程序中，并检查我的 CPU 周期都花在了哪里。该工具可以帮助您找出瓶颈是在您的代码中还是在 Hibernate 中或在网络通信中。

【解决方案2】：

您不需要在“选择”中进行交易。如果您使用 log4j，请禁用休眠调试。申请关联表“模式懒惰”。这很重要。

【讨论】：