Announcement Announcement Module
Collapse
No announcement yet.
Problem: @AfterThrowing with JPA in a scheduled method Page Title Module
Move Remove Collapse
X
Conversation Detail Module
Collapse
  • Filter
  • Time
  • Show
Clear All
new posts

  • Problem: @AfterThrowing with JPA in a scheduled method

    If I uncomment the first line of the getWeather() method so that a RollbackException is thrown, I see the expected behaviour (ie GetWeatherTxLoggerAspect.logException() is executed).

    If I leave the line commented out, but force the underlying database to barf (typically by ensuring that windDAO.save barfs with a duplicate key exception--ie by assserting a dummy record into the respective table) the logging does not get performed.

    it seems to me that getWeather() is being wrapped in a transaction and it is this wrapper that actually throws the exception. The question then becomes: how do I actually get hold of the fact that an exception occurred so that I can log it as I want to?

    Perhaps I should advise org.springframework.scheduling.timer.TimerFactoryB ean?

    Any suggestions gratefully accepted.

    Cheers,

    Alph.

    === collatoral follows: ===

    Code:
      @Transactional(propagation = Propagation.REQUIRES_NEW)
      public void getWeather()
        {
    //    if (1 == 1) throw new RollbackException("WHAT WHAT WHAT!!!");
     
        // at startup, find most recent timestamp
        if (lastRTs == null)
          {
          lastRTs = timestampDAO.findLatest().getStamp();
          logger.info("Found most recent Timestamp entry: " + lastRTs);
          }
    
        Reading r = getter.doGet();
        if (r != null)
          {
          Date rts = r.getTimestamp();
          logger.info("NEW timestamp: " + rts + "; OLD=" + lastRTs);
          if (!rts.equals(lastRTs))
            {
            lastRTs = rts;
            Timestamp ts = new Timestamp(rts);
            timestampDAO.save(ts);
            humidityDAO.save(new Humidity(ts, 0, location, r.getHumidity()));
            temperatureDAO
                .save(new Temperature(ts, 0, location, r.getTemperature()));
            windDAO.save(new Wind(ts, 0, location, r.getSpeed(), r.getDirection()));
            }
          }
        }
    Logger aspect is:

    Code:
    ...
    @Aspect
    public class GetWeatherTxLoggerAspect
      {
      @AfterThrowing(throwing = "t", pointcut = "execution(* au.com.transentia.weather.timer.GetWeatherTask.getWeather(..))")
      public void logException(Throwable t)
        {
        logger.error("***Logging Exception from GetWeatherTask.getWeather(): " + t, t);
        }
    
      ...
      }
    Configuration of the aspect stuff is:

    Code:
    ..
    <aop:aspectj-autoproxy />
    
    <bean id="getWeatherTxLogger"
       class="au.com.transentia.weather.timer.GetWeatherTxLoggerAspect" />
    ...
    Configuration of the Timer:

    Code:
    ...
    	<bean id="WeatherTask"
    		class="au.com.transentia.weather.timer.GetWeatherTask">
    		<property name="getter" ref="DummyBOMGetter" />
    		<property name="timestampDAO" ref="timestampDAO" />
    		<property name="temperatureDAO" ref="temperatureDAO" />
    		<property name="humidityDAO" ref="humidityDAO" />
    		<property name="windDAO" ref="windDAO" />
    	</bean>
    
    	<bean id="getWeatherMethodInvoker"
    		class="org.springframework.scheduling.timer.MethodInvokingTimerTaskFactoryBean">
    		<property name="targetObject" ref="WeatherTask" />
    		<property name="targetMethod" value="getWeather" />
    	</bean>
    
    	<bean id="scheduledTask"
    		class="org.springframework.scheduling.timer.ScheduledTimerTask">
    		<!-- wait 10 seconds before starting repeated execution -->
    		<property name="delay" value="10000" />
    		<!-- run every 5 mins -->
    		<property name="period" value="10000" />
    		<property name="timerTask" ref="getWeatherMethodInvoker" />
    	</bean>
    
    	<bean
    		class="org.springframework.scheduling.timer.TimerFactoryBean">
    		<property name="scheduledTimerTasks">
    			<list>
    				<ref bean="scheduledTask" />
    			</list>
    		</property>
    	</bean>
    Stacktrace excerpt for ('bad' behaviour) persistence exception case:

    Code:
    0:36:02,640 INFO  [STDOUT] [TopLink Warning]: 2006.12.02 08:36:02.640--UnitOfWork(12721409)--Thread(Thread[org.springframework.scheduling.timer.TimerFactoryBean,5,jboss])--Exception [TOPLINK-4002] (Oracle TopLink Essentials - 9.1 (Build b25)): oracle.toplink.essentials.exceptions.DatabaseException
    Internal Exception: com.mysql.jdbc.exceptions.MySQLIntegrityConstraintViolationException: Duplicate entry '1313' for key 1Error Code: 1062
    Call:INSERT INTO WIND (ID, PERIOD, DIRECTION, SPEED, loc_lat, loc_long, TIMESTAMP_ID) VALUES (?, ?, ?, ?, ?, ?, ?)
    	bind => [1313, 0, NE, 8.8, 50.0, 50.0, 1310]
    Query:InsertObjectQuery(au.com.transentia.weather.model.entity.Wind@a0187c)
    20:36:02,671 ERROR [MethodInvokingTimerTaskFactoryBean] Invocation of method 'getWeather' on target object [au.com.transentia.weather.timer.GetWeatherTask@748417] failed
    java.lang.reflect.InvocationTargetException
    	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    	at java.lang.reflect.Method.invoke(Method.java:585)
    	at org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:270)
    	at org.springframework.scheduling.support.MethodInvokingRunnable.run(MethodInvokingRunnable.java:79)
    	at org.springframework.scheduling.timer.DelegatingTimerTask.run(DelegatingTimerTask.java:60)
    	at java.util.TimerThread.mainLoop(Timer.java:512)
    	at java.util.TimerThread.run(Timer.java:462)
    Caused by: org.springframework.transaction.UnexpectedRollbackException: JPA transaction unexpectedly rolled back (maybe marked rollback-only after a failed operation); nested exception is javax.persistence.RollbackException: Exception [TOPLINK-4002] (Oracle TopLink Essentials - 9.1 (Build b25)): oracle.toplink.essentials.exceptions.DatabaseException
    Internal Exception: com.mysql.jdbc.exceptions.MySQLIntegrityConstraintViolationException: Duplicate entry '1313' for key 1Error Code: 1062
    Call:INSERT INTO WIND (ID, PERIOD, DIRECTION, SPEED, loc_lat, loc_long, TIMESTAMP_ID) VALUES (?, ?, ?, ?, ?, ?, ?)
    	bind => [1313, 0, NE, 8.8, 50.0, 50.0, 1310]
    Query:InsertObjectQuery(au.com.transentia.weather.model.entity.Wind@a0187c)
    	at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:422)
    	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:611)
    	at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:581)
    	at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:307)
    	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:117)
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
    	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
    	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
    	at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:615)
    	at au.com.transentia.weather.timer.GetWeatherTask$$EnhancerByCGLIB$$f7662012.getWeather(<generated>)
    	... 9 more
    
    
    SNIP...SNIP...
    
    Caused by: com.mysql.jdbc.exceptions.MySQLIntegrityConstraintViolationException: Duplicate entry '1313' for key 1
    	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:931)

  • #2
    This could be something to do with ordering. I've had problems before when two aspects are applied. If the order is Transaction then Logging, a manually thrown exception would be logged. If you are using something like Hibernate, the exception would only be thrown when the session is flushed, more than likely when the transaction is committing. To test this you could do a flush after the save and the logging should be there.

    There is some information in the manual about ordering of advice.
    http://www.springframework.org/docs/...dvice-ordering
    http://www.springframework.org/docs/...just-tx-advice

    This might also be useful.
    http://forum.springframework.org/sho...er+transaction
    Last edited by karldmoore; Dec 2nd, 2006, 06:09 AM. Reason: Added missing link

    Comment


    • #3
      Setting order to 1 did the job

      Many thanks, much appreciated!

      I knew about ordering, I just didn't think that it applied to the situation I had.

      Alph
      Last edited by alpheratz; Dec 2nd, 2006, 09:59 PM. Reason: fixed up typo

      Comment


      • #4
        Originally posted by alpheratz View Post
        Many thanks, much appreciated!
        I knew about ordering, I just didn't think that it applied to the situation I had.
        I have to admit it caught me out at first, glad you sorted it anyway!
        Good luck.

        Karl

        Comment

        Working...
        X