Spring + Hibernate 事务需要 25 秒啥都不做
Posted
技术标签:
【中文标题】Spring + Hibernate 事务需要 25 秒啥都不做【英文标题】:Spring + Hibernate transaction takes 25 seconds doing nothingSpring + Hibernate 事务需要 25 秒什么都不做 【发布时间】:2010-10-12 16:18:39 【问题描述】:我有一个使用 Spring + Hibernate 的 Java 应用程序。我有一个非常简单的事务,最近才开始需要很长时间才能执行(~25 秒),尽管它没有进行任何模糊/复杂的查询,并且根据日志,这 25 秒是在 Hiberante 的代码中花费的。浏览器只是挂在那里等到它完成......
事务通过注解完成,使用 org.springframework.orm.hibernate3.LocalSessionFactoryBean 作为会话工厂,使用 org.springframework.orm.hibernate3.HibernateTransactionManager 作为事务管理器。
对于 Hibernate 的缓存,我使用的是 Memcached,但这应该不是问题,根据日志,至少在此期间它没有触及缓存....
我在这里提交相关的日志:
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|HibernateTransactionManager] Found thread-bound Session [org.hibernate.impl.SessionImpl@a04a093] for Hibernate transaction
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|HibernateTransactionManager] Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@35ca1808]
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|HibernateTransactionManager] Creating new transaction with name [com.quebicoca.api.service.PaymentService.buy]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|HibernateTransactionManager] Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@a04a093]
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|HibernateTransactionManager] Exposing Hibernate transaction as JDBC transaction [com.mysql.jdbc.JDBC4Connection@66efd0ce]
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|TransactionSynchronizationManager] Bound value [org.springframework.jdbc.datasource.ConnectionHolder@a75b92e] for key [org.springframework.jdbc.datasource.DriverManagerDataSource@1420ca8b] to thread [http-8080-12]
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|TransactionSynchronizationManager] Initializing transaction synchronization
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|TransactionInterceptor] Getting transaction for [com.quebicoca.api.service.PaymentService.buy]
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate3.SessionHolder@3538ce1b] for key [org.hibernate.impl.SessionFactoryImpl@c4be179] bound to thread [http-8080-12]
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|HibernateTransactionManager] Found thread-bound Session [org.hibernate.impl.SessionImpl@a04a093] for Hibernate transaction
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|TransactionSynchronizationManager] Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@a75b92e] for key [org.springframework.jdbc.datasource.DriverManagerDataSource@1420ca8b] bound to thread [http-8080-12]
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|HibernateTransactionManager] Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@36d0805f]
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|HibernateTransactionManager] Participating in existing transaction
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|TransactionInterceptor] Getting transaction for [com.quebicoca.api.service.PaymentService.buy]
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate3.SessionHolder@3538ce1b] for key [org.hibernate.impl.SessionFactoryImpl@c4be179] bound to thread [http-8080-12]
[DEBUG] [2010-10-09 @ 07:25:55] [http-8080-25|HashCodeKeyStrategy] Transformed key [UserOrder_holders] to hashCode [-1959252437]
[DEBUG] [2010-10-09 @ 07:25:55] [http-8080-25|HashCodeKeyStrategy] Final cache key: [org.hibernate.cache.UpdateTimestampsCache:0:-1959252437]
[DEBUG] [2010-10-09 @ 07:25:55] [http-8080-25|MemcachedCache] Memcache.set(org.hibernate.cache.UpdateTimestampsCache:0:-1959252437)
[DEBUG] [2010-10-09 @ 07:25:55] [http-8080-25|SpyMemcache] MemcachedClient.set(org.hibernate.cache.UpdateTimestampsCache:0:-1959252437)
...
[DEBUG] [2010-10-09 @ 07:25:55] [http-8080-25|DispatcherServlet] Successfully completed request
[DEBUG] [2010-10-09 @ 07:25:55] [http-8080-25|TransactionSynchronizationManager] Removed value [org.springframework.orm.hibernate3.SessionHolder@5862af29] for key [org.hibernate.impl.SessionFactoryImpl@c4be179] from thread [http-8080-25]
[DEBUG] [2010-10-09 @ 07:25:55] [http-8080-25|OpenSessionInViewFilter] Closing single Hibernate Session in OpenSessionInViewFilter
[DEBUG] [2010-10-09 @ 07:25:55] [http-8080-25|SessionFactoryUtils] Closing Hibernate Session
[DEBUG] [2010-10-09 @ 07:25:55] [http-8080-25|ExceptionTranslationFilter] Chain processed normally
[DEBUG] [2010-10-09 @ 07:25:55] [http-8080-25|SecurityContextPersistenceFilter] SecurityContextHolder now cleared, as request processing completed
[DEBUG] [2010-10-09 @ 07:25:56] [http-8080-12|TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate3.SessionHolder@3538ce1b] for key [org.hibernate.impl.SessionFactoryImpl@c4be179] bound to thread [http-8080-12]
[DEBUG] [2010-10-09 @ 07:25:56] [http-8080-12|TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate3.SessionHolder@3538ce1b] for key [org.hibernate.impl.SessionFactoryImpl@c4be179] bound to thread [http-8080-12]
[DEBUG] [2010-10-09 @ 07:25:56] [http-8080-12|HibernateTemplate] Found thread-bound Session for HibernateTemplate
[DEBUG] [2010-10-09 @ 07:25:56] [http-8080-12|HashCodeKeyStrategy] Transformed key [UserOrder] to hashCode [-1966312925]
[DEBUG] [2010-10-09 @ 07:25:56] [http-8080-12|HashCodeKeyStrategy] Final cache key: [org.hibernate.cache.UpdateTimestampsCache:0:-1966312925]
在 25 秒间隔之前记录的最后一件事是:
[DEBUG] [2010-10-09 @ 07:25:30] [http-8080-12|TransactionSynchronizationManager] 检索值 [org.springframework.orm.hibernate3.SessionHolder@3538ce1b] 键 [org.hibernate. impl.SessionFactoryImpl@c4be179] 绑定到线程 [http-8080-12]
我是此日志期间唯一登录的人,我关闭了除我自己以外的所有人从运行在 Tomcat 前面的 Apache 的访问。
欢迎任何想法。
编辑:
根据要求添加了我的订单类:
@Entity
@Table(name = "UserOrder")
@Cache(usage = CacheConcurrencyStrategy.READ_WRITE)
public class Order
@Id
@GeneratedValue(strategy = GenerationType.AUTO)
private Long id;
@ManyToOne(optional = false)
private Deal deal;
@CollectionOfElements
private Map<String, Integer> holders;
@ManyToOne(optional = false)
private User user;
@org.hibernate.annotations.Type(type = "org.joda.time.contrib.hibernate.PersistentDateTime")
@Column(nullable = false)
private DateTime buyingDate;
@Column(nullable = false)
@Enumerated(EnumType.STRING)
private OrderState state;
private BigDecimal payedWithUserCredit;
@Column(nullable = false)
private int quantity;
@Column(nullable = false)
private String secret;
private boolean mailSent;
@Enumerated(EnumType.STRING)
private PaymentMethod paymentMethod;
编辑 2:
Afeter 建议 Spy Memcached 可能有事我决定回到 EHCache。
情况变得更糟(1:16 悬空)。日志:
[DEBUG] [2010-10-13 @ 04:28:47] [http-8080-1|HibernateTransactionManager] Triggering beforeCommit synchronization
[DEBUG] [2010-10-13 @ 04:28:47] [http-8080-1|HibernateTransactionManager] Triggering beforeCompletion synchronization
[DEBUG] [2010-10-13 @ 04:28:47] [http-8080-1|HibernateTransactionManager] Initiating transaction commit
[DEBUG] [2010-10-13 @ 04:28:47] [http-8080-1|HibernateTransactionManager] Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@20360e46]
[DEBUG] [2010-10-13 @ 04:30:03] [http-8080-1|HibernateTransactionManager] Triggering afterCommit synchronization
[DEBUG] [2010-10-13 @ 04:30:03] [http-8080-1|HibernateTransactionManager] Triggering afterCompletion synchronization
[DEBUG] [2010-10-13 @ 04:30:03] [http-8080-1|TransactionSynchronizationManager] Clearing transaction synchronization
[DEBUG] [2010-10-13 @ 04:30:03] [http-8080-1|TransactionSynchronizationManager] Removed value [org.springframework.jdbc.datasource.ConnectionHolder@30c2ea0b] for key [org.springframework.jdbc.datasource.DriverManagerDataSource@614a616] from thread [http-8080-1]
[DEBUG] [2010-10-13 @ 04:30:03] [http-8080-1|HibernateTransactionManager] Not closing pre-bound Hibernate Session [org.hibernate.impl.SessionImpl@20360e46] after transaction
[DEBUG] [2010-10-13 @ 04:30:03] [http-8080-1|TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate3.SessionHolder@839c6c7] for key [org.hibernate.impl.SessionFactoryImpl@6fbae5f5] bound to thread [http-8080-1]
[DEBUG] [2010-10-13 @ 04:30:03] [http-8080-1|DriverManagerDataSource] Creating new JDBC DriverManager Connection to [jdbc:mysql://localhost/quebicoca]
[DEBUG] [2010-10-13 @ 04:30:03] [http-8080-1|TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate3.SessionHolder@839c6c7] for key [org.hibernate.impl.SessionFactoryImpl@6fbae5f5] bound to thread [http-8080-1]
我完全迷路了......
【问题讨论】:
由于日志消息的过去时态,我假设(可能不正确)检索会话持有者在合理的时间内完成。 UserOrder 是您的课程之一吗?如果是,它是什么样的? Jeff:不,来自TransactionSynchronizationManager
的消息意味着检索结束。 Memcached 也可能是一个问题,因为 HashCodeKeyStrategy
是 hibernate-memcached 的一个类。
我为 Jeff 添加了 Order 的代码。希望它对这个问题有所启发......
【参考方案1】:
想通了!
在@Transactional 方法中,我会这样做:
orderDAO.save(order);
user.addOrder(order);
因此订单将被保存,并添加到用户的订单集中。
当调用保存时,插入订单,但不是为持有人。
当退出该方法时,Hibernate 会检查会话中的所有模型,以查看还有哪些需要持久化(这应该表明只剩下 UserOrder_holder)。似乎永远需要通过用户的订单和相关的交易(其中大部分在不同的订单中重复)来解决这个问题。而且我不是在谈论一个庞大的数据库,用于检索订单的查询只会从数据库中返回 17 行......这很蹩脚。
无论如何,让 Order 与 Deal 的关系变得懒惰解决了这个问题,至少目前,t 可能会在稍后出现更多 Orders。
【讨论】:
以上是关于Spring + Hibernate 事务需要 25 秒啥都不做的主要内容,如果未能解决你的问题,请参考以下文章