Announcement Announcement Module
Collapse
No announcement yet.
AfterReturningAdvice with Hibernate Question Page Title Module
Move Remove Collapse
X
Conversation Detail Module
Collapse
  • Filter
  • Time
  • Show
Clear All
new posts

  • AfterReturningAdvice with Hibernate Question

    I am implementing an audit scheme in Spring using the AfterReturningAdvice with the RegExpMethodPointcutAdvisor and BeanNameAutoProxyCreator. Basically, I'm inserting a record into my audit table whenever a save or update method is called in my DAO (which is basically a wrapper around getHibernateTemplate().save() or .update().

    Context Files
    Code:
    	<!-- Will create a system audit entry for any object creation. -->
    	<bean id="auditEventAdvice" class="com.company.common.interceptor.audit.AuditEventAfterReturningAdvice">
    		<property name="auditEventDAO"><ref bean="auditEventDAO"/></property>
    	</bean>
    
        <bean id="auditEventAdvisor" class="org.springframework.aop.support.RegexpMethodPointcutAdvisor">
    		<property name="advice"><ref bean="auditEventAdvice"/></property>
    		<property name="patterns">
    		<list>
    			<value>.*save</value>
    			<value>.*update</value>
    		</list>
    		</property>
    	</bean>
    
    	<bean id="daoProxyCreator" class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator">
            <property name="beanNames">
                <list>
                	<value>*DAO</value>
                </list>
            </property>
            <property name="interceptorNames">
                <list>
                	<value>hibernateInterceptor</value> //Disregard
                     <value>loggingInterceptor</value> //Disregard
                    <value>auditEventAdvisor</value>
                </list>
            </property>
        </bean>
    Advice Implementation
    Code:
    package com.company.common.interceptor.audit;
    
    import java.lang.reflect.Method;
    
    import org.springframework.aop.AfterReturningAdvice;
    
    import com.company.common.domain.WISDomain;
    import com.company.common.domain.audit.AuditEvent;
    import com.company.common.service.dao.audit.AuditEventDAO;
    
    /**
     * Class <code>AuditEventAfterReturningAdvice</code> is the method after return advice
     * that inserts an audit event record into the database on record save or update.
     */
    public class AuditEventAfterReturningAdvice implements AfterReturningAdvice &#123;
    
    	private AuditEventDAO auditEventDAO;
    
    	/**
    	 * @see org.springframework.aop.AfterReturningAdvice#afterReturning&#40;java.lang.Object, java.lang.reflect.Method, java.lang.Object&#91;&#93;, java.lang.Object&#41;
    	 */
    	public void afterReturning&#40;Object arg0, Method arg1, Object&#91;&#93; args,	Object arg3&#41; throws Throwable &#123;
    
    		WISDomain domainObject = &#40;WISDomain&#41;args&#91;0&#93;;
    		// Now insert the audit event for the object.
    		AuditEvent auditEvent = new AuditEvent&#40;&#41;;
    		auditEvent.setObjectId&#40;domainObject.getId&#40;&#41;&#41;;
    		auditEvent.setModifiedBy&#40;domainObject.getLastModifiedBy&#40;&#41;&#41;;
    		auditEvent.setModifiedDate&#40;domainObject.getLastModified&#40;&#41;&#41;;
    		auditEventDAO.save&#40;auditEvent&#41;;
    	&#125;
    
    	/**
    	 * @param auditEventDAO The auditEventDAO to set.
    	 */
    	public void setAuditEventDAO&#40;AuditEventDAO auditEventDAO&#41; &#123;
    		this.auditEventDAO = auditEventDAO;
    	&#125;
    &#125;
    Okay, now when I call the save method the audit event is inserted correctly after the insert call is completed. However, when I call the update, the audit event is inserted before the update. I am judging this by the sql output by hibernate in my logs. Here is a snippet from that:

    Code:
    - Entering method 'save' in class &#91;com.company.common.service.dao.reference.hibernate.AltDAOImpl&#93;
    - Exiting method 'save' in class &#91;com.company.common.service.dao.reference.hibernate.AltDAOImpl&#93;
    - Performance statistics for method &#91;com.company.common.service.dao.reference.hibernate.AltDAOImpl.save&#93;&#58;
    15 ms. &#40;Hits=1  Avg=15 ms. Total=15 ms. Min=15 ms. Max=15 ms. Active=0  Avg Active=1  Max Active=1  First access=2/9/05 10&#58;23&#58;34 AM  Last access=2/9/05 10&#58;23&#58;34 AM  &#41;
    Hibernate&#58; insert into W_ALT &#40;updateCounter, DESCRIPTION, VALUE, createdDate, createdBy, lastModifiedDate, lastModifiedBy, enabled, id&#41; values &#40;?, ?, ?, ?, ?, ?, ?, ?, ?&#41;
    Hibernate&#58; insert into W_AUDIT_EVENT &#40;VERSION, MODIFIEDBY, MODIFIEDDATE, OBJECT_ID, ID&#41; values &#40;?, ?, ?, ?, ?&#41;
    
    - Entering method 'update' in class &#91;com.company.common.service.dao.reference.hibernate.AltDAOImpl&#93;
    - Exiting method 'update' in class &#91;com.company.common.service.dao.reference.hibernate.AltDAOImpl&#93;
    - Performance statistics for method &#91;com.company.common.service.dao.reference.hibernate.AltDAOImpl.update&#93;&#58;
    16 ms. &#40;Hits=1  Avg=16 ms. Total=16 ms. Min=16 ms. Max=16 ms. Active=0  Avg Active=1  Max Active=1  First access=2/9/05 10&#58;23&#58;34 AM  Last access=2/9/05 10&#58;23&#58;34 AM  &#41;
    Hibernate&#58; insert into W_AUDIT_EVENT &#40;VERSION, MODIFIEDBY, MODIFIEDDATE, OBJECT_ID, ID&#41; values &#40;?, ?, ?, ?, ?&#41;
    Hibernate&#58; update W_ALT set updateCounter=?, DESCRIPTION=?, VALUE=?, lastModifiedDate=?, lastModifiedBy=?, enabled=? where id=? and updateCounter=?
    Any help would be appreciated. My thought on this would be that the audit event need only be applied after successful insert or update of the object records. Thus, if an exception occurs and no modifications are made, no audit event exists.

    Thanks in advance.

  • #2
    Have you been able to verify, perhaps by a log message, that the advice is actually getting called after the call to Hibernates save() or saveOrUpdate() methods.

    At first glance it seems like you have everything in order - but this could be to do with the order in which Hibernate flushes out commands within in a transactions - maybe you could try flushing manually after the update?

    Rob

    Comment


    • #3
      Thanks.

      Originally posted by robh
      Have you been able to verify, perhaps by a log message, that the advice is actually getting called after the call to Hibernates save() or saveOrUpdate() methods.

      At first glance it seems like you have everything in order - but this could be to do with the order in which Hibernate flushes out commands within in a transactions - maybe you could try flushing manually after the update?

      Rob
      I have verified it's running after method execution by throwing it into debug in Eclipse and breakpointing. However, what confused me was the fact that the hibernate trace was in the order it was. I guess I will add another after advice (or just put a method name sniff into my current after advice) to flush the session only on the update call and try that. Thanks for the help.

      Brian

      Comment


      • #4
        I put the explicit flush in the update method and no luck.

        Comment


        • #5
          Well, strangely enough by dumb luck I've found the fix. Not that I know exactly why it does fix it. However, when I place my advisor before the HibernateInterceptor in the BeanName proxy list. It resolves the issue. Why it works originally on save and not update, I have no idea. I'm going to attach the Spring and Hibernate source into Eclipse and try to debug it.

          I will update this thread with info, as I find it.

          Here's the new proxy:

          Code:
          <bean id="daoProxyCreator" class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator"> 
                  <property name="beanNames"> 
                      <list> 
                         <value>*DAO</value> 
                      </list> 
                  </property> 
                  <property name="interceptorNames"> 
                      <list> 
                          <value>auditEventAdvisor</value>
                         <value>hibernateInterceptor</value> //Disregard 
                           <value>loggingInterceptor</value> //Disregard 
                      </list> 
                  </property> 
              </bean>

          Comment


          • #6
            Similar problem

            I'm having a similar problem where I have an AfterReturningAdvice implementation to index objects after they are inserted into a database via Hibernate. With logging enabled I've followed the chain of events through and the HibernateTransactionManager is commiting the transaction but not closing the session before the aspect attempts to load the object to index, and thus does not find the just-commited object.

            These log lines illustrate the issue:

            Code:
            HibernateTransactionManager - Creating new transaction
            HibernateTransactionManager - Opened new session &#91;net.sf.hibernate.impl.SessionImpl@537c91&#93; for Hibernate transaction
            HibernateTransactionManager - Exposing Hibernate transaction as JDBC transaction &#91;org.apache.commons.dbcp.PoolableConnection@e1b0db&#93;
            HibernateTransactionManager - Triggering beforeCommit synchronization
            HibernateTransactionManager - Triggering beforeCompletion synchronization
            HibernateTransactionManager - Initiating transaction commit
            HibernateTransactionManager - Committing Hibernate transaction on session &#91;net.sf.hibernate.impl.SessionImpl@537c91&#93;
            RecipeSearchBizLuceneImpl - Unable to load object type &#91;i&#93; by key &#91;153&#93; for indexing
            HibernateTransactionManager - Triggering afterCompletion synchronization
            HibernateTransactionManager - Closing Hibernate session &#91;net.sf.hibernate.impl.SessionImpl@537c91&#93; after transaction
            The "Unable to load object" line is the error the index advice experiences, it is trying to call load() from Hibernate with the ID of the object just commited.

            I thought that AfterReturningAdvice would trigger after the completion of the HibernateTransactionManager advice, but it is not, even though it is configured after the transaction interceptor.

            Do transaction interceptors also wrap around AfterReturningAdvice interceptors?

            Comment

            Working...
            X