Spring + Hibernate транзакция занимает 25 секунд, ничего не делая - PullRequest
Новая
       14

Spring + Hibernate транзакция занимает 25 секунд, ничего не делая

5 голосов
/ 12 октября 2010

У меня есть приложение Java, использующее Spring + Hibernate. У меня довольно простая транзакция, которая только недавно начала выполняться ДЕЙСТВИТЕЛЬНО долго (~ 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]

Я был единственным, кто вошел в систему во время этого журнала, я закрыл доступ для всех, кроме меня, с Apache, запущенного перед Tomcat.

Любые идеи приветствуются.

EDIT:

Добавлен мой класс 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 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:

Более легкие предложения 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]

Я совершенно потерян ...

1 Ответ

2 голосов
/ 13 октября 2010

Разобрался!

В этом методе @Transactional я сделал бы что-то вроде этого: 

orderDAO.save(order);
user.addOrder(order);

Таким образом, порядок будет сохранен и добавлен в набор пользователя.orders.

Когда вызывалось сохранение, была вставлена ​​вставка для заказа, но не для держателя.

При выходе из метода Hibernate просматривал все модели в сеансе, чтобы посмотреть, чтоостальное необходимо сохранить (что должно указывать на то, что остался только UserOrder_holder).Похоже, потребовалось бы НАВСЕГДА попытаться выяснить это с помощью пользовательских заказов и связанных с ними сделок (большинство из которых повторяются среди разных заказов).И я не говорю об огромной базе данных, запрос, используемый для получения ордеров, просто вернул бы 17 строк из базы данных ... Это просто хромает.

В любом случае, отношение Ордена к сделке ленивым решенопроблема, по крайней мере на данный момент, может позже всплыть с большим количеством заказов.

Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.

Нет похожих вопросов

...