我有一个使用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.hibernate.impl.SessionFactoryImpl]检索值[org.springframework.orm.hibernate3.SessionHolder@3538ce1b] @ c4be179]绑定线程[http-8080-12]
我是唯一一个在这个日志中登录的人,我关闭了除了我以外的所有人从Tomcat前面运行的Apache访问.
欢迎任何想法.
编辑:
根据要求添加了我的Order类:
@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 Mapholders; @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建议间谍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]
我强行失去了......