Hi!

I have an existing JEE application (running on Wildfly 10) with about 100 entity-classes where I now want to use Envers to enable versioning of the entity data.

Migrating the whole data model to support Envers seems to work quite well so far, but I have found a handful of entity classes where a QueryException is triggered when I navigate a certain association.

I managed to create a stripped-down Hibernate/Envers test application small enough to show the problem, but without all the overhead of my "real" JEE application.

My test application produces exact the same exception on exact the same type of association and I will use this application to describe the problem here.

You can find a tar file of this application attached to this posting.  There is also a DDL SQL script you can use to set up a test database.

I'm using PostgreSQL as RDBMS, you will have to change the DDL script and the persistence.xml file in order to run the application with another database backend.

Now to the problem...

The association in question is a special map like this:

@Audited 
public class Category { 
[...]   
  private Map<Item, Value> categoryItem = new HashMap<>(); 
[...] 
}

where Item is another Entity and Value is some value-object.

I have mapped this association like this:

<hibernate-mapping package="enverstest.model" default-access="field" >
   <class name="Category" table="category">
 [...]
     <map name="categoryItem" table="category_item">
        <key column="category_id" not-null="true" />
        <map-key-many-to-many column="item_id" class="Item"/>
        <composite-element class="Value" >
          <property name="number" column="number" />
          <property name="text" column="text" />
        </composite-element>
      </map>
  </class>
 </hibernate-mapping>

This mapping works in principle. Without Envers I can save, modify and read all the data in the Category and Item entities as well as in the Value object associated with a Category entity, indexed with an Item entity.

With Envers enabled, I can create the entities and Envers fills all the auditing tables, including the category_item table with historic data.

But when I load a historic view of any Category entity using the AuditQuery#forEntiesAtRevision() API and when I then try to access the categoryItem property of the returned Category entity in some way, I get the following exception:

org.hibernate.QueryException: could not resolve property: originalId.rev_type of: enverstest.model.Item_r

This exception comes from Hibernate when it tries to translate a query created by Envers in order to load the historic data for the map from the database.

The query created by Envers looks like this:

select new list(ee__, e__)
     from category_item_r ee__,
          enverstest.model.Item_r e__
    where ee__.originalId.mapkey_id = e__.originalId.id
      and ee__.originalId.Category_id = :Category_id
      and e__.originalId.rev_begin.id <= :revision
      and ee__.originalId.rev_begin.id <= :revision
      and ee__.originalId.rev_type != :delrevisiontype
      and e__.originalId.rev_type != :delrevisiontype
      and (e__.rev_end.id > :revision or e__.rev_end is null)
      and (ee__.rev_end.id > :revision or ee__.rev_end is null)

When I annotate the categoryItem property with @NotAudited the exception is gone, but of course then versioning is disabled also.

Please see the attached tar archive for a complete test application.

In order to produce the problem, you have to set up a database manually using the provided ddl.sql script and adjust the persistence.xml file accordingly to your environment.

There is a JUnit test class CategoryTest which contains the relevant queries. If you set the variable showEnversError in this test to true, the test will throw an exception. If you set this variable to false, the test will succeed.

The test application is implemented as Maven project, a mvn test in the root directory of the project should be sufficient to run the test.

This is what I get when i run the test with showEnversError set to false:

andreas@ahnote:~/workspace/enverstest> mvn test
[INFO] Scanning for projects...
[INFO]                                                                        
[INFO] ------------------------------------------------------------------------
[INFO] Building Hibernate Envers Test 1.0-SNAPSHOT
[INFO] ------------------------------------------------------------------------
[...]
------------------------------------------------------- 
T E S T S 
-------------------------------------------------------
Running enverstest.model.CategoryTest
 WARN [rManagerConnectionProviderImpl:  70] HHH10001002: Using Hibernate built-in connection pool (not for production use!)

===== Fill Database =====

===== Database filled ===== 

===== Check current entities ===== 

===== Load historic data ===== 

Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.729 sec 

Results :

Tests run: 1, Failures: 0, Errors: 0, Skipped: 0 

[INFO] ------------------------------------------------------------------------ 
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 8.817 s
[INFO] Finished at: 2017-06-23T14:03:28+02:00
[INFO] Final Memory: 18M/182M
[INFO] ------------------------------------------------------------------------

And this is what I get when i run the test with showEnversError set to true:

andreas@ahnote:~/workspace/enverstest> mvn test 
[INFO] Scanning for projects... 
[INFO]                                                                          
[INFO] ------------------------------------------------------------------------ 
[INFO] Building Hibernate Envers Test 1.0-SNAPSHOT 
[INFO] ------------------------------------------------------------------------ 
[...] 
Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 5.499 sec <<< FAILURE! 
testEnvers(enverstest.model.CategoryTest)  Time elapsed: 5.389 sec  <<< ERROR! 
java.lang.IllegalArgumentException: org.hibernate.QueryException: could not resolve property: originalId.rev_type of: enverstest.model.Item_r [select new list(ee__, e__) from category_item_r ee__, enverstest.model.Item_r e__ where ee__.originalId.Category_id = :Category_id and e__.originalId.rev_begin.id <= :revision and ee__.originalId.rev_begin.id <= :revision and ee__.originalId.rev_type != :delrevisiontype and e__.originalId.rev_type != :delrevisiontype and (ee__.originalId.mapkey_id = e__.originalId.id or (ee__.originalId.mapkey_id is null and e__.originalId.id is null)) and (e__.rev_end.id > :revision or e__.rev_end is null) and (ee__.rev_end.id > :revision or ee__.rev_end is null)]         
         at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:131)         
         at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:155)         
         at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:162)         
         at org.hibernate.internal.AbstractSharedSessionContract.createQuery(AbstractSharedSessionContract.java:663)
         at org.hibernate.internal.AbstractSharedSessionContract.createQuery(AbstractSharedSessionContract.java:102)
         at org.hibernate.envers.internal.entities.mapper.relation.query.AbstractRelationQueryGenerator.getQuery(AbstractRelationQueryGenerator.java:55)
         at org.hibernate.envers.internal.entities.mapper.relation.lazy.initializor.AbstractCollectionInitializor.initialize(AbstractCollectionInitializor.java:49)
         at org.hibernate.envers.internal.entities.mapper.relation.lazy.proxy.MapProxy.checkInit(MapProxy.java:34)
         at org.hibernate.envers.internal.entities.mapper.relation.lazy.proxy.MapProxy.get(MapProxy.java:64)
         at enverstest.model.Category.getValue(Category.java:50)
         at enverstest.model.CategoryTest.testEnvers(CategoryTest.java:139)
         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
         at java.lang.reflect.Method.invoke(Method.java:498)
         at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
         at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
         at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
         at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
         at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
         at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
         at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
         at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
         at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
         at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
         at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
         at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
         at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
         at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
         at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
         at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252)
         at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141)
         at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112)
         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
         at java.lang.reflect.Method.invoke(Method.java:498)
         at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
         at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
         at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
         at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
         at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75) 
Caused by: org.hibernate.QueryException: could not resolve property: originalId.rev_type of: enverstest.model.Item_r [select new list(ee__, e__) from category_item_r ee__, enverstest.model.Item_r e__ where ee__.originalId.Category_id = :Category_id and e__.originalId.rev_begin.id <= :revision and ee__.originalId.rev_begin.id <= :revision and ee__.originalId.rev_type != :delrevisiontype and e__.originalId.rev_type != :delrevisiontype and (ee__.originalId.mapkey_id = e__.originalId.id or (ee__.originalId.mapkey_id is null and e__.originalId.id is null)) and (e__.rev_end.id > :revision or e__.rev_end is null) and (ee__.rev_end.id > :revision or ee__.rev_end is null)]
         at org.hibernate.QueryException.generateQueryException(QueryException.java:120)
         at org.hibernate.QueryException.wrapWithQueryString(QueryException.java:103)
         at org.hibernate.hql.internal.ast.QueryTranslatorImpl.doCompile(QueryTranslatorImpl.java:217)
         at org.hibernate.hql.internal.ast.QueryTranslatorImpl.compile(QueryTranslatorImpl.java:141)
         at org.hibernate.engine.query.spi.HQLQueryPlan.(HQLQueryPlan.java:115)
         at org.hibernate.engine.query.spi.HQLQueryPlan.(HQLQueryPlan.java:77)
         at org.hibernate.engine.query.spi.QueryPlanCache.getHQLQueryPlan(QueryPlanCache.java:153)
         at org.hibernate.internal.AbstractSharedSessionContract.getQueryPlan(AbstractSharedSessionContract.java:546)
         at org.hibernate.internal.AbstractSharedSessionContract.createQuery(AbstractSharedSessionContract.java:655)
         ... 38 more 
Caused by: org.hibernate.QueryException: could not resolve property: originalId.rev_type of: enverstest.model.Item_r
         at org.hibernate.persister.entity.AbstractPropertyMapping.propertyException(AbstractPropertyMapping.java:62)
         at org.hibernate.persister.entity.AbstractPropertyMapping.toColumns(AbstractPropertyMapping.java:77)
         at org.hibernate.persister.entity.BasicEntityPropertyMapping.toColumns(BasicEntityPropertyMapping.java:43)
         at org.hibernate.persister.entity.AbstractEntityPersister.toColumns(AbstractEntityPersister.java:1829)
         at org.hibernate.hql.internal.ast.tree.FromElementType.toColumns(FromElementType.java:442)
         at org.hibernate.hql.internal.ast.tree.FromElementType.toColumns(FromElementType.java:408)
         at org.hibernate.hql.internal.ast.tree.FromElement.toColumns(FromElement.java:516)
         at org.hibernate.hql.internal.ast.tree.DotNode.getColumns(DotNode.java:123)
         at org.hibernate.hql.internal.ast.tree.DotNode.initText(DotNode.java:250)
         at org.hibernate.hql.internal.ast.tree.DotNode.resolve(DotNode.java:225)
         at org.hibernate.hql.internal.ast.tree.FromReferenceNode.resolve(FromReferenceNode.java:114)
         at org.hibernate.hql.internal.ast.tree.DotNode.resolveFirstChild(DotNode.java:167)
         at org.hibernate.hql.internal.ast.HqlSqlWalker.lookupProperty(HqlSqlWalker.java:694)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.addrExpr(HqlSqlBaseWalker.java:5003)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.expr(HqlSqlBaseWalker.java:1286)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.exprOrSubquery(HqlSqlBaseWalker.java:4707)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.comparisonExpr(HqlSqlBaseWalker.java:4199)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.logicalExpr(HqlSqlBaseWalker.java:2138)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.logicalExpr(HqlSqlBaseWalker.java:2066)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.logicalExpr(HqlSqlBaseWalker.java:2063)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.logicalExpr(HqlSqlBaseWalker.java:2063)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.logicalExpr(HqlSqlBaseWalker.java:2063)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.whereClause(HqlSqlBaseWalker.java:815)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.query(HqlSqlBaseWalker.java:609)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.selectStatement(HqlSqlBaseWalker.java:313)
         at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.statement(HqlSqlBaseWalker.java:261)
         at org.hibernate.hql.internal.ast.QueryTranslatorImpl.analyze(QueryTranslatorImpl.java:266)
         at org.hibernate.hql.internal.ast.QueryTranslatorImpl.doCompile(QueryTranslatorImpl.java:189)
         ... 44 more

Results :  

Tests in error:   
  testEnvers(enverstest.model.CategoryTest): org.hibernate.QueryException: could not resolve property: originalId.rev_type of: enverstest.model.Item_r [select new list(ee__, e__) from category_item_r ee__, enverstest.model.Item_r e__ where ee__.originalId.Category_id = :Category_id and e__.originalId.rev_begin.id <= :revision and ee__.originalId.rev_begin.id <= :revision and ee__.originalId.rev_type != :delrevisiontype and e__.originalId.rev_type != :delrevisiontype and (ee__.originalId.mapkey_id = e__.originalId.id or (ee__.originalId.mapkey_id is null and e__.originalId.id is null)) and (e__.rev_end.id > :revision or e__.rev_end is null) and (ee__.rev_end.id > :revision or ee__.rev_end is null)] 
 
Tests run: 1, Failures: 0, Errors: 1, Skipped: 0

I tested this with Hibernate 5.0.12.Final as well as with Hibernate 5.2.10.Final. With both versions I get the same behaviour.

To me this looks like Envers is producing illegal Hibernate queries.

But why?

Is there a bug in my mapping, in the way I use Envers, or is this even a bug in Envers?

How can I make this association work with Envers?

Any idea, anyone?

Thanks!

- andreas

Message was edited by: Andreas Haumer in order to make it more readable (I hope it works now. This editor really needs a pre-view function and a better support for code fragments...)