Through the years I’ve encountered a recurring requirement. Partners need to log changes to the database for auditing and legal purposes. To satisfy this requirement you could add logging to every save/update/delete call in your code. Or better yet, you could create an aspect that wraps these calls. While these would certainly work Hibernate provides a convenient interceptor.
In this article I will show you how to add a simple logger to Hibernate.
Start with a Test
As an avid TDD practitioner I will of coarse start with a test. Here is the final version of the test that I used to drive my code.
package com.sourceallies.logging;
import static org.junit.Assert.assertEquals;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.verifyNoMoreInteractions;
import java.util.Date;
import java.util.List;
import javax.annotation.Resource;
import org.apache.commons.logging.Log;
import org.hibernate.Criteria;
import org.hibernate.SessionFactory;
import org.hibernate.classic.Session;
import org.junit.Before;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;
import org.springframework.transaction.annotation.Transactional;
import com.sourceallies.Person;
@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration
public class HibernateInterceptorTest {
@Resource
private SessionFactory sessionFactory;
@Resource
private HibernateInterceptor hibernateInterceptor;
private Session currentSession;
private Log logger;
private static final Date NOW = new Date();
@Before
public void setUp(){
logger = mock(Log.class);
currentSession = sessionFactory.getCurrentSession();
hibernateInterceptor.setLogger(logger);
}
@Test
@Transactional
public void testSaveLogging(){
saveOrUpdate(createPerson());
assertEquals(1, findAll().size());
verify(logger).info("Saving Person [firstName=testFirst, lastName=testLast, birthDate=" + NOW + "].");
verifyNoMoreInteractions(logger);
}
@Test
@Transactional
public void testUpdateLogging(){
saveOrUpdate(createPerson());
List<Person> people = findAll();
assertEquals(1, people.size());
Person firstPerson = people.get(0);
firstPerson.setFirstName("testFirst2");
saveOrUpdate(firstPerson);
currentSession.flush();
verify(logger).info("Saving Person [firstName=testFirst, lastName=testLast, birthDate=" + NOW + "].");
verify(logger).info("Updating Person [firstName=testFirst2, lastName=testLast, birthDate=" + NOW + "].");
verifyNoMoreInteractions(logger);
}
@Test
@Transactional
public void testDeleteLogging(){
saveOrUpdate(createPerson());
List<Person> people = findAll();
assertEquals(1, people.size());
Person firstPerson = people.get(0);
delete(firstPerson);
currentSession.flush();
verify(logger).info("Saving Person [firstName=testFirst, lastName=testLast, birthDate=" + NOW + "].");
verify(logger).info("Deleting Person [firstName=testFirst, lastName=testLast, birthDate=" + NOW + "].");
verifyNoMoreInteractions(logger);
}
@Transactional
public void saveOrUpdate(Person person) {
currentSession.saveOrUpdate(person);
currentSession.flush();
}
@Transactional
public void delete(Person person) {
currentSession.delete(person);
}
@SuppressWarnings("unchecked")
private List<Person> findAll() {
Criteria criteria = currentSession.createCriteria(Person.class);
List<Person> people = criteria.list();
return people;
}
private Person createPerson() {
Person person = new Person("testFirst", "testLast", NOW);
return person;
}
}
I used a mock logger to gather information from the interceptor.
Spring Configuration
Here is the configuration required for the interceptor.
<bean id="sessionFactory" class="org.springframework.orm.hibernate3.annotation.AnnotationSessionFactoryBean">
...
<property name="dataSource" ref="dataSource" />
<property name="entityInterceptor" ref="hibernateInterceptor"/>
</bean>
<bean id="transactionManager" class="org.springframework.orm.hibernate3.HibernateTransactionManager">
<property name="sessionFactory" ref="sessionFactory" />
</bean>
...
<context:component-scan base-package="com.sourceallies" />
...
The ‘entityInterceptor’ property on the ‘sessionFactory’ takes a Hibernate interceptor.
Entity
@Entity
public class Person {
@Id
@GeneratedValue(strategy=GenerationType.AUTO)
private Long id = -1L;
@Column
private String firstName;
@Column
private String lastName;
@Column
private Date birthDate;
...
@Override
public String toString() {
return "Person [firstName=" + firstName + ", lastName="
+ lastName + ", birthDate=" + birthDate + "]";
}
}
For this example you need to implement the ‘toString’ method on the entity being logged.
Interceptor
Here is the interceptor code.
package com.sourceallies.logging;
import java.io.Serializable;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.hibernate.EmptyInterceptor;
import org.hibernate.type.Type;
import org.springframework.stereotype.Component;
@Component
public class HibernateInterceptor extends EmptyInterceptor {
private static final long serialVersionUID = 1L;
private Log logger = LogFactory.getLog(HibernateInterceptor.class);
@Override
public void onDelete(Object entity, Serializable id, Object[] state,
String[] propertyNames, Type[] types) {
log("Deleting", id, entity);
super.onDelete(entity, id, state, propertyNames, types);
}
@Override
public boolean onFlushDirty(Object entity, Serializable id,
Object[] currentState, Object[] previousState,
String[] propertyNames, Type[] types) {
log("Updating", id, entity);
return super.onFlushDirty(entity, id, currentState, previousState,
propertyNames, types);
}
@Override
public boolean onSave(Object entity, Serializable id, Object[] state,
String[] propertyNames, Type[] types) {
log("Saving", id, entity);
return super.onSave(entity, id, state, propertyNames, types);
}
protected void setLogger(Log logger) {
this.logger = logger;
}
private void log(String action, Serializable id, Object entity) {
logger.info(action + " " + entity + ".");
}
}
While the ‘onSave’ and ‘onDelete’ methods are clearly named the ‘onUpdate’ method appears to be missing. With a little research it quickly becomes obvious that ‘onFlushDirty’ is used for updates.
Logging database activity is this simple.
Here is the complete code. Hibernate Logging Zip
