【发布时间】：2015-01-31 12:16:45
【问题描述】：
我遇到了一个问题，即休眠刷新策略在处理订单上的一组订单项时会随着时间的推移而变慢。当后续更新被调用到 JBoss Seam 更新时，减速会随着时间的推移而增加。
代码的业务流程接受包含“n”行项目的订单，为业务目的修改每个行项目，在该行项目上调用 seam/hibernate update()，然后移动到下一个行项目。当调用 update() 时，Hibernate 刷新策略会立即响应。但是随着代码在行项目列表中向下移动，Hibernate 速度变慢（几乎成倍增长）。启用日志记录后，我可以看到减速开始为几秒钟，然后是一两分钟，然后是 5 分钟以上，然后是 20 分钟以上。所有处理集合中相同的订单行项目。它不会改变集合的大小，不会添加或删除任何项目。
我启用了休眠事务的跟踪，并在输出中发现 org.hibernate.event.def.AbstractFlushingEventListener 在调用之间的某处遇到问题：
prepareCollectionFlushes(session);
和
flushEntities(event);
我已经根据 Hibernate 创建的日志条目将其追溯到这两个方法调用之间的问题：
2014-12-02 17:50:30,808 DEBUG [org.hibernate.engine.CollectionEntry] (http-0.0.0.0-8443-2) Collection dirty: [com.companioncabinet.ccs.domain.data.Job.jobPhases#10324859]
2014-12-02 18:19:09,015 TRACE [org.hibernate.event.def.AbstractFlushingEventListener] (http-0.0.0.0-8443-2) Flushing entities and processing referenced collections
注意 17:50 的消息组，然后是 18:19 的时间间隔。代码都在 Hibernate 的 AbstractFlushingEventListner 中。我检查了 Hibernate 源代码，发现它们的代码如下所示：
prepareCollectionFlushes(session);
// now, any collections that are initialized
// inside this block do not get updated - they
// are ignored until the next flush
persistenceContext.setFlushing(true);
try {
flushEntities(event);
flushCollections(session);
}
finally {
persistenceContext.setFlushing(false);
}
出现的消息来自：
prepareCollectionFlushes(session);
和
flushingEntities(event);
prepareCollectionFlushes 方法调用 CollectionEntry.preFlush 生成“Collection dirty”消息。
这里是所有涉及的方法：
prepareCollectionFlushes
/**
* Initialize the flags of the CollectionEntry, including the
* dirty check.
*/
private void prepareCollectionFlushes(SessionImplementor session) throws HibernateException {
// Initialize dirty flags for arrays + collections with composite elements
// and reset reached, doupdate, etc.
log.debug("dirty checking collections");
final List list = IdentityMap.entries( session.getPersistenceContext().getCollectionEntries() );
final int size = list.size();
for ( int i = 0; i < size; i++ ) {
Map.Entry e = ( Map.Entry ) list.get( i );
( (CollectionEntry) e.getValue() ).preFlush( (PersistentCollection) e.getKey() );
}
}
预刷新
public void preFlush(PersistentCollection collection) throws HibernateException {
boolean nonMutableChange = collection.isDirty() &&
getLoadedPersister()!=null &&
!getLoadedPersister().isMutable();
if (nonMutableChange) {
throw new HibernateException(
"changed an immutable collection instance: " +
MessageHelper.collectionInfoString( getLoadedPersister().getRole(), getLoadedKey() )
);
}
dirty(collection);
if ( log.isDebugEnabled() && collection.isDirty() && getLoadedPersister() != null ) {
log.debug(
"Collection dirty: " +
MessageHelper.collectionInfoString( getLoadedPersister().getRole(), getLoadedKey() )
);
}
setDoupdate(false);
setDoremove(false);
setDorecreate(false);
setReached(false);
setProcessed(false);
}
脏
/**
* Determine if the collection is "really" dirty, by checking dirtiness
* of the collection elements, if necessary
*/
private void dirty(PersistentCollection collection) throws HibernateException {
boolean forceDirty = collection.wasInitialized() &&
!collection.isDirty() && //optimization
getLoadedPersister() != null &&
getLoadedPersister().isMutable() && //optimization
( collection.isDirectlyAccessible() || getLoadedPersister().getElementType().isMutable() ) && //optimization
!collection.equalsSnapshot( getLoadedPersister() );
if ( forceDirty ) {
collection.dirty();
}
}
上述块中的 collection.dirty() 将 PersistenceCollection 脏设置为 true。
flushEntities
/**
* 1. detect any dirty entities
* 2. schedule any entity updates
* 3. search out any reachable collections
*/
private void flushEntities(FlushEvent event) throws HibernateException {
log.trace("Flushing entities and processing referenced collections");
...remainder of code omitted since the delay happens before the above log entry appears
手头有所有代码，没有什么明显的事情发生。延迟期间代码中没有任何事情发生。一切似乎都停止了。
数据库是 PostgreSQL。我已启用所有查询的日志记录。当我将最后一个查询与延迟之前对齐时，它似乎是所有脏实体的重新加载。当我运行记录的选择时，它需要不到 1 毫秒。
我知道这些是旧版本，需要“升级”。但是，最好指出一个特定的缺陷、错误或众所周知的性能问题作为触发升级的催化剂。
感谢收看！
orm.xml
<persistence-unit-metadata>
<persistence-unit-defaults>
<entity-listeners>
<entity-listener class="org.jboss.seam.security.EntitySecurityListener"/>
</entity-listeners>
</persistence-unit-defaults>
</persistence-unit-metadata>
persistence.xml
<persistence-unit name="DS1" transaction-type="JTA">
<provider>org.hibernate.ejb.HibernatePersistence</provider>
<jta-data-source>java:/DS1</jta-data-source>
<properties>
<property name="hibernate.archive.autodetection" value="class" />
<property name="hibernate.search.default.indexBase" value="/home/lucene/DS1" />
<!-- Binds the EntityManagerFactory to JNDI where Seam can look it up.
This is only relevant when the container automatically loads the persistence unit, as is the case in JBoss AS 5. -->
<property name="jboss.entity.manager.factory.jndi.name" value="java:/DS1EntityManagerFactory"/>
</properties>
</persistence-unit>
hibernate.properties 为空
ds.xml
<local-tx-datasource>
<jndi-name>DS1</jndi-name>
<connection-url>jdbc:postgresql://127.0.0.1:5432/data</connection-url>
<driver-class>org.postgresql.Driver</driver-class>
<user-name>a_user</user-name>
<password>a_pw</password>
<idle-timeout-minutes>90</idle-timeout-minutes>
<new-connection-sql>select 1</new-connection-sql>
<check-valid-connection-sql>select 1</check-valid-connection-sql>
</local-tx-datasource>
数据库日志摘录
2014-12-08 19:43:19 EST LOG: duration: 0.000 ms execute <unnamed>: update PurchaseOrder set active=$1, createdby=$2, createdStamp=$3, ...
2014-12-08 19:43:19 EST LOG: duration: 0.000 ms execute <unnamed>: select orderlines0_.purchaseorderid as purchas66_18_5_, ...
2014-12-08 19:49:29 EST LOG: duration: 0.000 ms execute <unnamed>: update PurchaseOrder set active=$1, createdby=$2, createdStamp=$3, ...
2014-12-08 19:49:29 EST LOG: duration: 0.000 ms execute <unnamed>: select orderlines0_.purchaseorderid as purchas66_18_5_, ...
【问题讨论】：
标签： hibernate jpa jboss seam jboss5.x