Possible bug in AuditReader.find()
mordecus Sep 28, 2011 10:38 AMI'm auditing some order data using Hibernate envers and Spring (hibernate version 3.6.7.Final, Spring version 3.0.6.RELEASE). The auditing part works fine - I can see revisions getting created as objects are created, modified and deleted. I've also customized the RevisionEntity to capture some additional data (who made the change) and that is getting stored properly as well.
However, I'd now like to start retrieving some of the audit data. I've written methods to get a list of revisions for a given domain object; get the revision entity metadata for a given revision (so I know when the change was made and who made it) and I now want to implement a method that will allow me to retrieve revision x for a given domain object. And that's where I'm running into a problem.
Here's the set up - I'm auditing an object named "ProvisioningOrder". In my testing, I first persist a Provisioning Order in the database; and then I modify it. This creates two revisions: revision 1 is where the provisioning order is created, revision 2 is where the order is modified. Looking at the data in the audit tables, everything is there and it's all correct.
I then run a small unit test that retrieves the existing revision numbers for the ProvisioningOrder and then for each revision number, grabs the revision entity, prints it to console; and then grabs the actual revision instance and prints it to console as well.
I correctly get a list of revision numbers, containing "1" and "2".
I correctly get a list of Revision Entitiies which show when revision 1 and 2 were created and who made the change
But when I try to get the actual revisions 1 and 2 of my provisioning order, I respectively get "null" for revision 1 and an error for revision 2 (specifically, it's complaining that a dependent object (e911Info) with identifier 1 does not exist; even though it does exist in the database).
I think I know where the problem lies too: I turned on tracing on the Hibernate queries that get run, and the query that's getting run against the audit table when I execute getReader().find(ProvisioningOrder.class, id, revisionNumber); is wrong. It runs:
DEBUG org.hibernate.SQL:logStatement select provisioni0_.id as id11_, provisioni0_.REV as REV11_, provisioni0_.REVTYPE as REVTYPE11_, provisioni0_.title as title11_, provisioni0_.end_customer as end5_11_, provisioni0_.creation_date as creation6_11_, provisioni0_.requested_date as requested7_11_, provisioni0_.completed_date as completed8_11_, provisioni0_.csa_id as csa9_11_, provisioni0_.type as type11_, provisioni0_.status as status11_, provisioni0_.creator as creator11_, provisioni0_.address_id as address13_11_, provisioni0_.e911_id as e14_11_, provisioni0_.did_request_id as did15_11_, provisioni0_.directory_listing_id as directory16_11_ from audit_tpn_prov_order provisioni0_ where (provisioni0_.REV=(select max(provisioni1_.REV) from audit_tpn_prov_order provisioni1_ where (provisioni1_.REV<=? )and(provisioni0_.id=provisioni1_.id )))and(provisioni0_.REVTYPE<>? )and(provisioni0_.id=? )
2011-09-28 10:11:47 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder:bind binding parameter [1] as [BIGINT] - 2
2011-09-28 10:11:47 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder:bind binding parameter [3] as [BIGINT] - 1
2011-09-28 10:11:47 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder:bind binding parameter [2] as [VARBINARY] - DEL
Note the parameter binding... parameter 2 is getting bound with the value "DEL". The problem is that this parameter is getting bound to provisioni0_REVTYPE<>?. In other words, the query AuditReader.find() is generating is trying to find rows in the audit table where the REVTYPE is NOT a delete. However, envers normally stores the REVTYPE as a number (0,1 and 2 respectively). Running a query that essentially is SELECT * from audit_table where REVTYPE <> 'DEL' will never return a result.
If I manually run this query myself against the database, it finds no results. If, instead, I change the 'DEL' with '2' (which is correct), the query correctly returns revision 1.
So to me, it seems as if envers is generating a flawed SQL query when running AuditReader.find() - any ideas on how to fix this?
Source code below:
Hibernate mapping for ProvisioningOrder:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<!-- Generated 14-May-2010 4:17:41 PM by Hibernate Tools 3.2.4.GA -->
<hibernate-mapping>
<class name="com.thinkingphones.provorders.model.ProvisioningOrder" table="tpn_prov_order">
<cache usage="read-write"/>
<id name="id" type="java.lang.Long">
<column name="id" />
<generator class="identity" />
</id>
<many-to-one name="addressInfo" class="com.thinkingphones.provorders.model.AddressInfo" fetch="join" cascade="all" unique="true">
<column name="address_id"/>
</many-to-one>
<many-to-one name="e911Info" class="com.thinkingphones.provorders.model.E911Info" cascade="all" fetch="join" unique="true">
<column name="e911_id"/>
</many-to-one>
<many-to-one name="didRequest" class="com.thinkingphones.provorders.model.DIDRequest" cascade="all" fetch="join" unique="true">
<column name="did_request_id"/>
</many-to-one>
<many-to-one name="directoryListingInfo" class="com.thinkingphones.provorders.model.DirectoryListingInfo" cascade="all" fetch="join">
<column name="directory_listing_id"/>
</many-to-one>
<property name="title" type="string" not-null="true">
<column name="title" length="255" />
</property>
<property name="endCustomer" type="string">
<column name="end_customer" length="255"/>
</property>
<property name="creationDate" type="timestamp" not-null="true">
<column name="creation_date" />
</property>
<property name="requestedDate" type="timestamp">
<column name="requested_date"/>
</property>
<property name="completedDate" type="timestamp">
<column name="completed_date"/>
</property>
<property name="csaID" type="java.lang.Long">
<column name="csa_id"/>
</property>
<property name="type">
<column name="type" length="20" not-null="true" />
<type name="org.hibernate.type.EnumType">
<param name="enumClass">
com.thinkingphones.provorders.model.ProvisioningOrderType
</param>
<param name="type">12</param>
</type>
</property>
<property name="status">
<column name="status" length="20" not-null="true" />
<type name="org.hibernate.type.EnumType">
<param name="enumClass">
com.thinkingphones.provorders.model.ProvisioningOrderStatus
</param>
<param name="type">12</param>
</type>
</property>
<property name="creatorID" type="string">
<column name="creator" length="255"/>
</property>
<list name="commentList" table="tpn_prov_order_list_comment" fetch="subselect" lazy="false" cascade="all">
<key column="prov_order_id" not-null="true" />
<list-index column="list_index"/>
<many-to-many column="comment_id" class="com.thinkingphones.provorders.model.Comment" />
</list>
</class>
</hibernate-mapping>
SessionFactory in Spring:
<!-- define Hibernate Session factories -->
<bean id="sessionFactory"
class="org.springframework.orm.hibernate3.LocalSessionFactoryBean">
<property name="dataSource" ref="datasource"/>
<property name="mappingResources">
<list>
<value>hibernate/AddressInfo.hbm.xml</value>
<value>hibernate/Comment.hbm.xml</value>
<value>hibernate/DIDRequest.hbm.xml</value>
<value>hibernate/DIDReservation.hbm.xml</value>
<value>hibernate/DirectoryListingInfo.hbm.xml</value>
<value>hibernate/E911Info.hbm.xml</value>
<value>hibernate/ProvisioningOrder.hbm.xml</value>
<value>hibernate/RevisionEntity.hbm.xml</value>
</list>
</property>
<property name="hibernateProperties">
<props>
<prop key="hibernate.dialect">org.hibernate.dialect.MySQLDialect</prop>
<prop key="hibernate.cache.provider_class">org.hibernate.cache.EhCacheProvider</prop>
<prop key="hibernate.show.sql">true</prop>
<prop key="hibernate.query.factory_class">org.hibernate.hql.classic.ClassicQueryTranslatorFactory</prop>
<prop key="org.hibernate.envers.audit_table_prefix">audit_</prop>
<prop key="org.hibernate.envers.audit_table_suffix"></prop>
<prop key="org.hibernate.envers.store_data_at_delete">true</prop>
</props>
</property>
<property name="eventListeners">
<map>
<entry key="post-insert" value-ref="enversListener" />
<entry key="post-update" value-ref="enversListener" />
<entry key="post-delete" value-ref="enversListener" />
<entry key="pre-collection-update" value-ref="enversListener" />
<entry key="pre-collection-remove" value-ref="enversListener" />
<entry key="post-collection-recreate" value-ref="enversListener" />
</map>
</property>
</bean>
DAO Object to query revision data:
public abstract class AbstractDomainObjectDAO<T extends DomainObject<?>> extends HibernateDaoSupport implements DomainObjectDAO<T> {
@Override
public Long persistNew(T dataObject) {
LOGGER.debug("Persisting " + dataObject + " to Hibernate");
Long id = (Long)this.getHibernateTemplate().save(dataObject);
return id;
}
@Override
public T fetchObject(Serializable id) {
return this.getHibernateTemplate().get(this.getDomainObjectClass(), id);
}
@Override
public T update(T dataObject) {
LOGGER.debug("Saving " +dataObject + " back to persistence store.");
T mergedObject = this.getHibernateTemplate().merge(dataObject);
return mergedObject;
}
@Override
public T remove(T dataObject) {
LOGGER.debug("Deleting "+ dataObject + " from persistence store.");
this.getHibernateTemplate().delete(dataObject);
return dataObject;
}
@Override
public T getRevision(Serializable id, Long revisionNumber) throws NotAuditedException, RevisionDoesNotExistException
{
LOGGER.debug("Loading " + getDomainObjectClass() +"(" + id+") at revision "+ revisionNumber);
return getReader().find(getDomainObjectClass(), id, revisionNumber);
}
@Override
public Number getCurrentRevisionNumber(Serializable id) throws RevisionDoesNotExistException
{
return getReader().getRevisionNumberForDate(new Date());
}
@Override
public RevisionEntity getRevisionEntity(Long revisionNumber) throws RevisionDoesNotExistException
{
RevisionEntity entity =this.getHibernateTemplate().get(RevisionEntity.class, revisionNumber);
return entity;
}
@Override
public List<Number> getRevisionNumbers(Serializable id) throws NotAuditedException
{
return getReader().getRevisions(getDomainObjectClass(), id);
}
@SuppressWarnings("unchecked")
public Class<T> getDomainObjectClass()
{
Class<?> c = this.getClass();
Type superTypeClass = c.getGenericSuperclass();
if (ParameterizedType.class.isAssignableFrom(superTypeClass.getClass()))
{
ParameterizedType superclass = (ParameterizedType) superTypeClass;
return (Class<T>) superclass.getActualTypeArguments()[0];
}
else
{
throw new IllegalArgumentException("Cannot determine parameterized class!");
}
}
protected AuditReader getReader()
{
Session session = this.getSession();
AuditReader reader = AuditReaderFactory.get(session);
return reader;
}
Unit Test to replicate problem:
@ContextConfiguration("classpath:spring/testContext.xml")
public class RevisionTests extends SpringTest{
private static final Logger LOGGER = LoggerFactory.getLogger(RevisionTests.class);
protected ProvisioningOrderDAO dao;
@Parameters({"id"})
@Test(groups="id")
public void doTest(Long id)
{
List<Number> revisionNumberList = dao.getRevisionNumbers(id);
for(Number revisionNumber : revisionNumberList)
{
LOGGER.debug("Revision " + revisionNumber.intValue());
RevisionEntity entity = dao.getRevisionEntity(revisionNumber.longValue());
LOGGER.debug("Revision Entity:" +entity.toString());
ProvisioningOrder order = dao.getRevision(id, revisionNumber.longValue());
LOGGER.debug("Revision object:" + order);
}
}
/**
* @return the dao
*/
public ProvisioningOrderDAO getDao() {
return dao;
}
/**
* @param dao the dao to set
*/
@Resource(name="provisioningOrderDAO")
public void setDao(ProvisioningOrderDAO dao) {
this.dao = dao;
}
}