-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 1 post ] 
Author Message
 Post subject: Cache related multithread bottleneck (UpdateTimestampsCache)
PostPosted: Wed Sep 08, 2010 7:45 am 
Newbie

Joined: Wed Sep 08, 2010 7:19 am
Posts: 1
Hi,

we are experiencing performance problems on production servers, which is associated with query cache. Apparently there is a SessionFactory-wide lock on the single instance of UpdateTimestampCache class. This lock is causing significant blocking issues on servers with 8 and more cores.

These are the methods in question:

Code:
public class UpdateTimestampsCache {
...

   public synchronized void preinvalidate(Serializable[] spaces) throws CacheException {
   ...

   public synchronized void invalidate(Serializable[] spaces) throws CacheException {
   ...

   public synchronized boolean isUpToDate(Set spaces, Long timestamp) throws HibernateException {
   ...


Thread telemetry screenshot from YourKit:
Image

Monitor backtrace report generated by YourKit:

Code:
Back traces

+-----------------------------------------------------------------------------------------------------------------------------------------+---------------------+------------------+
|                                                                  Name                                                                   |      Time (ms)      |      Count       |
+-----------------------------------------------------------------------------------------------------------------------------------------+---------------------+------------------+
|  +---org.hibernate.cache.UpdateTimestampsCache.invalidate(Serializable[])                                                               |  37 639 178   62 %  |  330 654   62 %  |
|  | |                                                                                                                                    |                     |                  |
|  | +---org.hibernate.engine.ActionQueue$AfterTransactionCompletionProcessQueue.afterTransactionCompletion(boolean)                      |                     |                  |
|  |   |                                                                                                                                  |                     |                  |
|  |   +---org.hibernate.engine.ActionQueue.afterTransactionCompletion(boolean)                                                           |                     |                  |
|  |     |                                                                                                                                |                     |                  |
|  |     +---org.hibernate.impl.SessionImpl.afterTransactionCompletion(boolean, Transaction)                                              |                     |                  |
|  |       |                                                                                                                              |                     |                  |
|  |       +---org.hibernate.jdbc.JDBCContext.afterNontransactionalQuery(boolean)                                                         |  33 492 067   55 %  |  295 298   56 %  |
|  |       | |                                                                                                                            |                     |                  |
|  |       | +---org.hibernate.impl.SessionImpl.afterOperation(boolean)                                                                   |                     |                  |
|  |       |   |                                                                                                                          |                     |                  |
|  |       |   +---org.hibernate.impl.SessionImpl.list(String, QueryParameters)                                                           |  23 260 227   38 %  |  205 708   39 %  |
|  |       |   |                                                                                                                          |                     |                  |
|  |       |   +---org.hibernate.impl.SessionImpl.get(String, Serializable)                                                               |   8 948 485   15 %  |   78 124   15 %  |
|  |       |   |                                                                                                                          |                     |                  |
|  |       |   +---org.hibernate.impl.SessionImpl.list(CriteriaImpl)                                                                      |   1 097 517    2 %  |    9 674    2 %  |
|  |       |   |                                                                                                                          |                     |                  |
|  |       |   +---org.hibernate.impl.SessionImpl.listCustomQuery(CustomQuery, QueryParameters)                                           |     185 836    0 %  |    1 792    0 %  |
|  |       |                                                                                                                              |                     |                  |
|  |       +---org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(boolean, Transaction)                                            |   3 607 634    6 %  |   31 301    6 %  |
|  |       | |                                                                                                                            |                     |                  |
|  |       | +---org.hibernate.transaction.JDBCTransaction.commit()                                                                       |   1 858 608    3 %  |   16 309    3 %  |
|  |       | |                                                                                                                            |                     |                  |
|  |       | +---org.hibernate.jdbc.JDBCContext.connectionCleanedUp()                                                                     |   1 743 032    3 %  |   14 955    3 %  |
|  |       | |                                                                                                                            |                     |                  |
|  |       | +---org.hibernate.transaction.JDBCTransaction.rollback()                                                                     |       5 994    0 %  |       37    0 %  |
|  |       |                                                                                                                              |                     |                  |
|  |       +---org.springframework.orm.hibernate3.SpringSessionSynchronization.afterCompletion(int)                                       |     539 476    1 %  |    4 055    1 %  |
|  |                                                                                                                                      |                     |                  |
|  +---org.hibernate.cache.UpdateTimestampsCache.isUpToDate(Set, Long)                                                                    |  22 618 644   37 %  |  196 432   37 %  |
|  | |                                                                                                                                    |                     |                  |
|  | +---org.hibernate.cache.StandardQueryCache.isUpToDate(Set, Long)                                                                     |                     |                  |
|  |   |                                                                                                                                  |                     |                  |
|  |   +---org.hibernate.cache.StandardQueryCache.get(QueryKey, Type[], boolean, Set, SessionImplementor)                                 |                     |                  |
|  |     |                                                                                                                                |                     |                  |
|  |     +---org.hibernate.loader.Loader.getResultFromQueryCache(SessionImplementor, QueryParameters, Set, Type[], QueryCache, QueryKey)  |                     |                  |
|  |       |                                                                                                                              |                     |                  |
|  |       +---org.hibernate.loader.Loader.listUsingQueryCache(SessionImplementor, QueryParameters, Set, Type[])                          |                     |                  |
|  |         |                                                                                                                            |                     |                  |
|  |         +---org.hibernate.loader.Loader.list(SessionImplementor, QueryParameters, Set, Type[])                                       |                     |                  |
|  |           |                                                                                                                          |                     |                  |
|  |           +---org.hibernate.loader.hql.QueryLoader.list(SessionImplementor, QueryParameters)                                         |  22 353 852   37 %  |  194 070   37 %  |
|  |           |                                                                                                                          |                     |                  |
|  |           +---org.hibernate.loader.criteria.CriteriaLoader.list(SessionImplementor)                                                  |     163 625    0 %  |    1 468    0 %  |
|  |           |                                                                                                                          |                     |                  |
|  |           +---org.hibernate.loader.custom.CustomLoader.list(SessionImplementor, QueryParameters)                                     |     101 165    0 %  |      894    0 %  |
|  |                                                                                                                                      |                     |                  |
|  +---org.hibernate.cache.UpdateTimestampsCache.preinvalidate(Serializable[])                                                            |     287 421    0 %  |    2 328    0 %  |
+-----------------------------------------------------------------------------------------------------------------------------------------+---------------------+------------------+

Generated by YourKit Java Profiler 8.0.19 8.9.2010 12:43:41


Judging from comments in UpdateTimestampsCache.java, this is a known (or at least anticipated) issue. Is there any workaround? Any plans on when this could be fixed?

We are using:
  • Hibernate 3.5.0
  • EhCache 2.1.0
  • Apache Tomcat 5.5.23
  • Java(TM) SE Runtime Environment (build 1.6.0_16-b01)
    Java HotSpot(TM) 64-Bit Server VM (build 14.2-b01, mixed mode)
  • 64-bit GNU/Linux 2.6.18-164.el5xen

Thanks,
Mirek


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 1 post ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.