-->
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.  [ 2 posts ] 
Author Message
 Post subject: StaleObjectStateException always logged on the error level
PostPosted: Tue Jun 10, 2008 7:38 am 
Newbie

Joined: Sun Jun 20, 2004 7:41 am
Posts: 7
Hi,

I use optimistic locking for one of the classes I wrote. Occasionally I get the subject mentioned org.hibernate.StaleObjectStateException, which gets logged internally by the org.hibernate.event.def.AbstractFlushingEventListener class. My question is why is that exception logged on the error level? This is precisely what I'm expecting to happen, as the code works in multiprocess and multithreaded environment so this is pretty normal that there may be many threads/processes trying to update the same row in the database, and the code is written with this in mind - I mean it handles concurrent modification exceptions so nothing gets screwed up and all data is perfectly consistent.

Cheers
Krzysztof

Hibernate version:
3.2.5

Full stack trace of any exception that occurs:

org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [ptv.vdp.LogFile#3139]
at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2407)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2307)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2607)
at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:92)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:142)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:596)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:709)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:678)
at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:319)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy13.update(Unknown Source)
at ptv.vdp.logs.service.WNBPersistenceServiceImpl.mergeLogFile(WNBPersistenceServiceImpl.java:262)
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:301)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy14.mergeLogFile(Unknown Source)
at ptv.vdp.logs.LogFileDBLoadingProcessorImpl.findAndSubmitLogFilesForLoading(LogFileDBLoadingProcessorImpl.java:255)
at ptv.vdp.logs.LogFileDBLoadingProcessorImpl.loadLogFilesIntoTheDatabase(LogFileDBLoadingProcessorImpl.java:318)
at ptv.vdp.logs.LogFileDbLoaderQuartzJob.executeInternal(LogFileDbLoaderQuartzJob.java:31)
at org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:86)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)


Last edited by hicnar on Wed Jun 11, 2008 11:33 am, edited 1 time in total.

Top
 Profile  
 
 Post subject:
PostPosted: Wed Jun 11, 2008 11:04 am 
Newbie

Joined: Sun Jun 20, 2004 7:41 am
Posts: 7
Ok, I think I've figured it out.

the exception is thrown from org.hibernate.event.def.AbstractFlushingEventListener.java:301
Code:
protected void performExecutions(EventSource session) throws HibernateException {

    log.trace("executing flush");

    try {
      session.getJDBCContext().getConnectionManager().flushBeginning();
      // we need to lock the collection caches before
      // executing entity inserts/updates in order to
      // account for bidi associations
      session.getActionQueue().prepareActions();
      session.getActionQueue().executeActions();
    }
    catch (HibernateException he) {
      log.error("Could not synchronize database state with session", he);
/* line # 301*/      throw he;
    }
    finally {
      session.getJDBCContext().getConnectionManager().flushEnding();
    }
  }


Logging this exception in line # 300 makes sense in all cases except for one - when optimistic locking is used. In that case the exception is an instance of org.hibernate.StaleObjectStateException (caught as HibernateException) and that when rethrown should be handled properly in the client code. This usually means - "another thread or process won the race for this particular object and updated/deleted it - so take appropriate steps or just ignore it and find yourself another object to work with".

In my oppinion logging this exception on the error level is a misuse, since it may trigger actions that are not adequate to the cause - for example (depending on the logging framework configuration) an email or a text message informing about this "error" may be sent to the system administrator whereas this in fact is not an error and is handled in the client code.

On the other hand, suppressing this class in the logging framework configuration so it is not capable of logging messages seems not to be a good option either.


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

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.