[Logo] Terracotta Discussion Forums (LEGACY READ-ONLY ARCHIVE)
  [Search] Search   [Recent Topics] Recent Topics   [Members]  Member Listing   [Groups] Back to home page 
[Register] Register / 
[Login] Login 
[Expert]
Messages posted by: Gleb  XML
Profile for Gleb -> Messages posted by Gleb [31] Go to Page: 1, 2, 3 Next 
Author Message

nelrahma wrote:

looks like you may need to put some hibernate-annotation jars in your classpath.
 


Hello MappingException appears just once. After that there are UnlockedSharedObjectException and infinite loops.
hibernate-annotation.jar is in tomcat/shared/lib. Do you mean it also should be added into classpath param for catalina? It's strange.

Please look at provided trace closely.
Terracotta tries to resolve reference to object and during that terracotta tries to create hibernate sessionFactory.
Why does terracotta try to start new sessionFactory? It's completely unpredictable behavior for me. It shouldn't hit database.
Could you please clarify this situation.

nelrahma wrote:

Thank you for the information, The while loop is there because the map that holds the Peer object in the L1 is a weak hash map. There might be a chance that the peer object got collected, that's why the while loop. Looks like the problem maybe with the lookup itself.
-Nabib 


Yeah. It can't find object. And trying again and again. And the question is Why it can't find it?

I've researched production logs again and I think I found the reason.
I found Exception thrown from the same controller

Code:
2008-06-18 21:17:50,428 INFO [com.tioti.web.spring.common.UrlHandlerMapping:55] - << NOT LOGGED >> Session:[F96DF3A3CADD
 B70118305A728B60B744], page:[/show/thesimpsons/about]
 2008-06-18 21:17:50,429 INFO [com.tioti.web.spring.common.UrlHandlerMapping:55] - << NOT LOGGED >> Session:[F96DF3A3CADD
 B70118305A728B60B744], page:[/show/thesimpsons/about]
 2008-06-18 21:17:50,447 INFO [org.hibernate.cfg.Configuration:1432] - configuring from resource: /hibernate.cfg.xml
 2008-06-18 21:17:50,448 INFO [org.hibernate.cfg.Configuration:1409] - Configuration resource: /hibernate.cfg.xml
 2008-06-18 21:17:50,462 ERROR [org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/].[tioti2]:723] - Servlet
 .service() for servlet tioti2 threw exception
 org.hibernate.MappingException: An AnnotationConfiguration instance is required to use <mapping class="com.tioti.domain.
 Show"/>
         at org.hibernate.cfg.Configuration.parseMappingElement(Configuration.java:1606)
         at org.hibernate.cfg.Configuration.parseSessionFactory(Configuration.java:1561)
         at org.hibernate.cfg.Configuration.doConfigure(Configuration.java:1540)
         at org.hibernate.cfg.Configuration.doConfigure(Configuration.java:1514)
         at org.hibernate.cfg.Configuration.configure(Configuration.java:1434)
         at org.hibernate.cfg.Configuration.configure(Configuration.java:1420)
         at org.terracotta.modules.hibernate_3_2_5.util.HibernateUtil.<clinit>(HibernateUtil.java:17)
         at java.lang.Class.forName0(Native Method)
         at java.lang.Class.forName(Class.java:247)
         at org.terracotta.modules.hibernate_3_2_5.object.applicator.HibernateProxyApplicator.getSession(HibernateProxyAp
 plicator.java:251)
         at org.terracotta.modules.hibernate_3_2_5.object.applicator.HibernateProxyApplicator.getNewInstance(HibernatePro
 xyApplicator.java:202)
         at com.tc.object.TCClassImpl.getNewInstanceFromNonDefaultConstructor(TCClassImpl.java:342)
         at com.tc.object.TCObjectFactoryImpl.getNewPeerObject(TCObjectFactoryImpl.java:50)
         at com.tc.object.ClientObjectManagerImpl.createNewPeer(ClientObjectManagerImpl.java:1128)
         at com.tc.object.TCObjectImpl.createPeerObjectIfNecessary(TCObjectImpl.java:184)
         at com.tc.object.TCObjectImpl.hydrate(TCObjectImpl.java:112)
         at com.tc.object.ClientObjectManagerImpl.lookup(ClientObjectManagerImpl.java:583)
         at com.tc.object.ClientObjectManagerImpl.lookupObject(ClientObjectManagerImpl.java:483)
         at com.tc.object.ClientObjectManagerImpl.lookupObject(ClientObjectManagerImpl.java:472)
         at com.tc.object.TCObjectPhysical.resolveReference(TCObjectPhysical.java:133)
         at com.tioti.domain.ShowHistory.__tc_getshow(ShowHistory.java)
         at com.tioti.domain.ShowHistory.getShow(ShowHistory.java:200)
         at com.tioti.domain.ShowHistory.<init>(ShowHistory.java:171)
         at com.tioti.web.spring.controller.ShowAboutController.handleGeneralRequest(ShowAboutController.java:59)
         at com.tioti.web.spring.controller.ShowPageBaseController.handleRequestInternal(ShowPageBaseController.java:73)
         at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
         at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java
 :48)
         at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:839)
         at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:774)
         at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:460)
         at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:415)
         at javax.servlet.http.HttpServlet.service(HttpServlet.java:690)
         at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
         at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:691)
         at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:469)
         at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:403)
         at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:301)
         at org.tuckey.web.filters.urlrewrite.RewrittenUrl.doRewrite(RewrittenUrl.java:189)
 :


There is the code in this controller:
Code:
        ShowHistory showBriefHistory = historyUIService.findLastActiveShowHistory(show.getShowId(), ShowPageType.SHOW_BREIF_DESCRIPTION);
         if (showBriefHistory != null) {
             showBriefHistory = new ShowHistory(showBriefHistory);
             if (user != null && showBriefHistory.getUser() != null) {
                 String flaggedReportSource = FlaggedHelper.generateRequestSource(FlaggedContentTypeEnum.SHOW_DESCRIPTION, FlaggedHelper.PARAM_BRIEF_HISTORY_ID, showBriefHistory.getId());
                 mav.addObject("briefFlaggedReportSource", flaggedReportSource);
             }
             String description = showBriefHistory.getDescription();
             description = TextUtils.changeHtmlTags(description);
             description = TextUtils.removeHtmlTags(description);
             showBriefHistory.setDescription(description);
             mav.addObject("showBriefHistory", showBriefHistory);
         }


In THIS method
ShowHistory showBriefHistory = historyUIService.findLastActiveShowHistory(show.getShowId(), ShowPageType.SHOW_BREIF_DESCRIPTION);
- hibernate loads ShowHistory, closes session and transaction and after that we put ShowHistory into ehcache (not into hibernate Level2 cache but into custom POJO cacche)

So sometimes controller throws MappingException
And sometimes after that another thread hangs up when trying perform
showBriefHistory = new ShowHistory(showBriefHistory);

What is the reason for this exception?

Hello!

I have essential news for this issue.
High CPU usage appeared again. One tomcat server has 50% and another 100%. I made statistic with two thread dumps during 10 min.
Then I've downloaded Terracotta sources. I compared src with my thread dumps.

And now I am completely sure i found the problem. It's infinite loop in the method of ClientObjectManagerImpl

Code:
   private Object lookupObject(ObjectID objectID, ObjectID parentContext, boolean noDepth) throws ClassNotFoundException {
     if (objectID.isNull()) return null;
     Object o = null;
     while (o == null) {
       final TCObject tco = lookup(objectID, parentContext, noDepth);
       if (tco == null) throw new AssertionError("TCObject was null for " + objectID);// continue;
 
       o = tco.getPeerObject();
       if (o == null) {
         reap(objectID);
       }
     }
     return o;
   }
 


It's look like tco.getPeerObject() always returns null. And object can't be resolved.
Please check atached statistic to acknowledge this behaviour.

Have you any ideas what is the reason?
I can't reproduce 200% cpu utilization at this point.
But I reproduced UnlockedSharedObjectException. I just added L1/4 to the cluster and exceptions appear again.

I retreived statistics at this point, see "incident session"

Could you at least confirm is it a bug and is it real to fix it?

It's important for me. Because I must decide. Continue using terracotta or perform clustering without terracotta by ehcache itself.
Hello
I think I have useful information which should help in research.

I've noticed another strange thing. There is great load average in the one of servers. Usually LA is small 0.01 but sometimes it jumps up to 3-4. It uses 200% cpu in 2 cpu box. After that load average on this server never come down.

I've made thread dump on cluster at this moment. And I can see on app1 box (which uses 200% cpu) many BLOCKED threads. For example

Code:
"TP-Processor57" Id=3131 BLOCKED on com.tc.object.ObjectID@b035cb owned by "TP-Processor12" Id=124
 	at com.tioti.domain.ShowHistory.__tc_getdescription(ShowHistory.java)
 	at com.tioti.domain.ShowHistory.getDescription(ShowHistory.java:217)
 	at com.tioti.web.spring.controller.SearchController.processShow(SearchController.java:173)
 	at com.tioti.web.spring.controller.SearchController.defaultAction(SearchController.java:105)


And it waits for

Code:
"TP-Processor12" Id=124 RUNNABLE
 	at java.lang.Object.notifyAll(Native Method)
 	at com.tc.util.Counter.increment(Counter.java:25)
 	at com.tc.util.Counter.increment(Counter.java:20)
 	at com.tc.object.ClientObjectManagerImpl.lookup(ClientObjectManagerImpl.java:531)
 	at com.tc.object.ClientObjectManagerImpl.lookupObject(ClientObjectManagerImpl.java:483)
 	at com.tc.object.ClientObjectManagerImpl.lookupObject(ClientObjectManagerImpl.java:472)
 	at com.tc.object.TCObjectPhysical.resolveReference(TCObjectPhysical.java:133)
 	at com.tioti.domain.ShowHistory.__tc_getshow(ShowHistory.java)


After a while I make another dump and saw all these threads were still blocked by the same thread.

Please take a look at the attached statistic file with both thread dumps.
Is it enough to find problem?

amiller wrote:
I'm guessing that based on your stack trace, you are using Spring AOP to do some sort of User lookup via HibernateTemplate using clustered ehcache? I'm trying to figure out how we could test something like this in house. Is there any other info you could share with respect to the objects being stored here? Or a very simple portion of your app?  


You are right we are using clustered ehcache as level2 for hibernate
We also have custom caching framework on top of ehcache and if problems begin it also fails, see trace below:
Code:
 2008-06-09 23:58:17,468 [TP-Processor18] ERROR com.tc.object.bytecode.Manager - Exception thrown
 com.tc.object.tx.UnlockedSharedObjectException:
 *******************************************************************************
 Attempt to access a shared object outside the scope of a shared lock.
 All access to shared objects must be within the scope of one or more shared locks defined in your Terracotta configurati
 on.
 Please alter the locks section of your Terracotta configuration so that this access is auto-locked or protected by a nam
 ed lock.
 
 For more information on this issue, please visit our Troubleshooting Guide at:
  http://terracotta.org/kit/troubleshooting
 
 
     Caused by Thread: TP-Processor18  in  VM(5)
     Shared Object Type: java.util.HashMap
 *******************************************************************************
 
         at com.tc.object.tx.ClientTransactionManagerImpl.getTransaction(ClientTransactionManagerImpl.java:300)
         at com.tc.object.tx.ClientTransactionManagerImpl.checkWriteAccess(ClientTransactionManagerImpl.java:313)
         at com.tc.object.bytecode.ManagerImpl.checkWriteAccess(ManagerImpl.java:697)
         at com.tc.object.bytecode.ManagerUtil.checkWriteAccess(ManagerUtil.java:378)
         at java.util.HashMap.__tc_put_logical(HashMap.java)
         at com.tcclient.cache.CacheDataStore.putData(CacheDataStore.java:152)
         at com.tcclient.ehcache.TimeExpiryMap.putData(TimeExpiryMap.java:74)
         at net.sf.ehcache.store.TimeExpiryMemoryStore.putData(TimeExpiryMemoryStore.java:91)
         at net.sf.ehcache.Cache.put(CacheTC.java:627)
         at net.sf.ehcache.Cache.put(CacheTC.java:572)
         at com.tioti.cache.CacheInterceptor.populateCache(CacheInterceptor.java:94)
         at com.tioti.cache.CacheInterceptor.proceedWithCache(CacheInterceptor.java:75)
         at com.tioti.cache.CacheInterceptor.invoke(CacheInterceptor.java:55)
         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
         at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:203)
         at $Proxy196.findTopHundredPopularGenreTags(Unknown Source)
         at com.tioti.web.spring.controller.IndexController.renderLogged(IndexController.java:78)
         at com.tioti.web.spring.controller.IndexController.defaultAction(IndexController.java:49)
         at sun.reflect.GeneratedMethodAccessor218.invoke(Unknown Source)
         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
         at java.lang.reflect.Method.invoke(Method.java:597)
         at org.springframework.web.servlet.mvc.multiaction.MultiActionController.invokeNamedMethod(MultiActionController
 .java:434)
         at org.springframework.web.servlet.mvc.multiaction.MultiActionController.handleRequestInternal(MultiActionContro
 ller.java:372)
         at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
         at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java
 :48)
         at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:839)
         at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:774)
         at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:460)
         at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:415)
         at javax.servlet.http.HttpServlet.service(HttpServlet.java:690)
         at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
         at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:691)
 :


That is why I think the problem is in ehcache integration (or may be in terracotta locking engine) not in hibernate integration. We are using terracotta only for clustering ehcache.

There were problems again last night after ~10 hours of work. After a while Exceptions have gone and all working well.
May be problem caused by environment errors like network fail or something like that. What are you thinking about that?
I am looking into terracotta server logs but there was nothing interesting last night.

amiller wrote:
If you could post the following information, it would help a lot:

- Terracotta version
- tc-config.xml
- ehcache TIM module version

 


I'm sorry
We are using terracotta 2.6.0 (final)
I don't know if its concerned with exception on client but i've seen many
warning in terracotta server logs
Code:
 2008-06-09 09:07:53,582 [WorkerThread(respond_to_request_stage,3)] WARN com.tc.net.core.TCConnection - Warning: Attempting to send a messaage of size 4379402 bytes
 
Hello
System is working for a while, then suddenly UnlockedSharedObjectException appears. I know It's mean changes without lock aquiring. But it's thrown from Ehcache code so locking should be created by Ehcache integration module. Also it works well aproximately 6 hours before exceptions.

Bellow is one of these exceptions:
Code:
 2008-06-06 03:53:39,024 ERROR [com.tioti.web.spring.common.ExceptionResolver:18] - Application exception
 com.tc.object.tx.UnlockedSharedObjectException:
 *******************************************************************************
 Attempt to access a shared object outside the scope of a shared lock.
 All access to shared objects must be within the scope of one or more shared locks defined in your Terracotta configurati
 on.
 Please alter the locks section of your Terracotta configuration so that this access is auto-locked or protected by a nam
 ed lock.
 
 For more information on this issue, please visit our Troubleshooting Guide at:
  http://terracotta.org/kit/troubleshooting
 
 
     Caused by Thread: TP-Processor13  in  VM(8)
     Shared Object Type: java.util.HashMap
 *******************************************************************************
 
         at com.tc.object.tx.ClientTransactionManagerImpl.getTransaction(ClientTransactionManagerImpl.java:300)
         at com.tc.object.tx.ClientTransactionManagerImpl.checkWriteAccess(ClientTransactionManagerImpl.java:313)
         at com.tc.object.bytecode.ManagerImpl.checkWriteAccess(ManagerImpl.java:697)
         at com.tc.object.bytecode.ManagerUtil.checkWriteAccess(ManagerUtil.java:378)
         at java.util.HashMap.__tc_put_logical(HashMap.java)
         at com.tcclient.cache.CacheDataStore.putData(CacheDataStore.java:152)
         at com.tcclient.ehcache.TimeExpiryMap.putData(TimeExpiryMap.java:74)
         at net.sf.ehcache.store.TimeExpiryMemoryStore.putData(TimeExpiryMemoryStore.java:91)
         at net.sf.ehcache.Cache.put(CacheTC.java:627)
         at net.sf.ehcache.Cache.put(CacheTC.java:572)
         at org.hibernate.cache.EhCache.put(EhCache.java:119)
         at org.hibernate.cache.ReadWriteCache.put(ReadWriteCache.java:159)
         at org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:159)
         at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:854)
         at org.hibernate.loader.Loader.doQuery(Loader.java:729)
         at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
         at org.hibernate.loader.Loader.doList(Loader.java:2213)
         at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2104)
         at org.hibernate.loader.Loader.list(Loader.java:2099)
         at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:378)
         at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
         at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
         at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
         at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
         at org.hibernate.impl.AbstractQueryImpl.uniqueResult(AbstractQueryImpl.java:811)
         at com.tioti.dao.HibernateUserDao$3.doInHibernate(HibernateUserDao.java:253)
         at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:369)
         at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:335)
         at com.tioti.dao.HibernateUserDao.findActiveUserByName(HibernateUserDao.java:249)
         at com.tioti.service.UserService.findActiveUser(UserService.java:92)
         at sun.reflect.GeneratedMethodAccessor266.invoke(Unknown Source)
         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
         at java.lang.reflect.Method.invoke(Method.java:597)
         at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
         at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:
 172)
 :
 


After restart tomcat it's working well and at the same time when one server is firing exceptions second server is working well too.
It's very sad problem on our production environment.
Could you help me?
Good news.
I've seen it already.
And i've started migration.
It's all right now
Ooo
I never heard about -Dcom.tc.loader.ext.name

I've fixed the problem by completely replacing java.ext.dirs by coresponding -cp

But it was hardly to find out the problem
because if i run without com.tc.loader.system.name app fails immedeately
during startup
Code:
 |17:25:03.515|  INFO [CacheManagerFactoryBean:90] - Initializing EHCache CacheManager
 com.tc.exception.TCClassNotFoundException: java.lang.ClassNotFoundException: No registered loader for description: Tomcat.shared, trying to load net.sf.ehcache.CacheManager
 	at com.tc.object.ClientObjectManagerImpl.lookupRoot(ClientObjectManagerImpl.java:640)
 	at com.tc.object.bytecode.ManagerImpl.lookupRoot(ManagerImpl.java:726)
 	at com.tc.object.bytecode.ManagerUtil.lookupRoot(ManagerUtil.java:325)
 	at net.sf.ehcache.CacheManager.__tc_getsingleton(CacheManager.java)
 	at net.sf.ehcache.CacheManager.create(CacheManager.java:465)
 	at org.springframework.cache.ehcache.EhCacheManagerFactoryBean.afterPropertiesSet(EhCacheManagerFactoryBean.java:94)
 	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1175)
 	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1145)
 	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:427)
 	at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:251)
 	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:144)
 	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:248)
 	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:160)
 	at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:261)
 	at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:109)
 	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1073)


And it's clear for me that to do
But if i specify com.tc.loader.system.name app starts well and looks fine
then at some point it throws strange class cast exception.

Anyway thank you.
Hello I ascertained the situation about ClassCastException.
It appears when I run standalone app with -Djava.ext.dirs=lib
to specify jars. And when I using -cp with full list of jars it works fine.

So -Dcom.tc.loader.system.name param doesn't shield me from classloader issue when i using java.ext.dirs
It's a little bit confusing because exception appears for non root object.
Ok let me know when you have any ideas.
Thank You.
Thank you.

I'd better wait for "proper" release of the tim-ehcache.
 
Profile for Gleb -> Messages posted by Gleb [31] Go to Page: 1, 2, 3 Next 
Go to:   
Powered by JForum 2.1.7 © JForum Team