AuditReader SQLException: Column 'col_1_1_' not found

[buzz3791]

I'm trying to use the Envers AuditReader to query some data persisted with auditing enabled.  However, when I try to run the query, I'm getting SQLException: Column 'col_1_1_' not found (details below).  The mapping involved seems to be

{code}
    @OneToMany(fetch=FetchType.EAGER, cascade=CascadeType.ALL, orphanRemoval=true)
    @OrderBy("id ASC") // Must use OrderBy instead of OrderColumn because the application is maintaining the index and it can't be linked to an OrderColumn (see JSR-317 Final, page 406, footnote 107).
    private List<CircuitTemplateFieldDescription> fieldDescriptions = new ArrayList<CircuitTemplateFieldDescription>();
{code}

Does this have something to do with the "What isn't and will not be supported" section in the Envers manual (http://docs.jboss.org/hibernate/envers/3.6/reference/en-US/html_single/#exceptions-wontbesupported)?  This section discusses the persisting but not the querying side.  We worked around the persisting a "Bag" problem by making sure no duplicates are in the "Bag".

{code}
 WARN  2011-05-17 14:39:18,857[main](JDBCExceptionReporter.java:233) - SQL Error: 0, SQLState: S0022
 ERROR 2011-05-17 14:39:18,857[main](JDBCExceptionReporter.java:234) - Column 'col_1_1_' not found.
com.rci.maxview.cm.persistence.api.CMPersistenceException: Caught exception while getting circuit template.
    at com.rci.maxview.cm.persistence.impl.CMJPAPersistenceStrategy.getCircuitTemplate(CMJPAPersistenceStrategy.java:394)
    at com.rci.maxview.cm.test.CmAudit.main(CmAudit.java:124)
Caused by: org.hibernate.exception.SQLGrammarException: could not execute query
    at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:92)
    at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
    at org.hibernate.loader.Loader.doList(Loader.java:2536)
    at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2276)
    at org.hibernate.loader.Loader.list(Loader.java:2271)
    at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:452)
    at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:363)
    at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
    at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1268)
    at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
    at org.hibernate.envers.entities.mapper.relation.lazy.initializor.AbstractCollectionInitializor.initialize(AbstractCollectionInitializor.java:62)
    at org.hibernate.envers.entities.mapper.relation.lazy.proxy.CollectionProxy.checkInit(CollectionProxy.java:50)
    at org.hibernate.envers.entities.mapper.relation.lazy.proxy.CollectionProxy.iterator(CollectionProxy.java:70)
    at com.rci.maxview.cm.structure.template.api.CircuitTemplate.getFieldDescriptions(CircuitTemplate.java:320)
    at com.rci.maxview.cm.structure.template.api.CircuitTemplate.toString(CircuitTemplate.java:727)
    at java.lang.String.valueOf(String.java:2826)
    at java.io.PrintStream.println(PrintStream.java:771)
    at com.rci.maxview.cm.persistence.impl.CMJPAPersistenceStrategy.getCircuitTemplate(CMJPAPersistenceStrategy.java:390)
    ... 1 more
Caused by: java.sql.SQLException: Column 'col_1_1_' not found.
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1075)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:929)
    at com.mysql.jdbc.ResultSetImpl.findColumn(ResultSetImpl.java:1145)
    at com.mysql.jdbc.ResultSetImpl.getLong(ResultSetImpl.java:3022)
    at com.mchange.v2.c3p0.impl.NewProxyResultSet.getLong(NewProxyResultSet.java:2469)
    at org.hibernate.type.descriptor.sql.BigIntTypeDescriptor$2.doExtract(BigIntTypeDescriptor.java:61)
    at org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:64)
    at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:253)
    at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:249)
    at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:229)
    at org.hibernate.type.ManyToOneType.hydrate(ManyToOneType.java:146)
    at org.hibernate.type.ComponentType.hydrate(ComponentType.java:593)
    at org.hibernate.type.ComponentType.nullSafeGet(ComponentType.java:308)
    at org.hibernate.type.ManyToOneType.hydrate(ManyToOneType.java:146)
    at org.hibernate.type.EntityType.nullSafeGet(EntityType.java:234)
    at org.hibernate.loader.hql.QueryLoader.getResultColumnOrRow(QueryLoader.java:403)
    at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:639)
    at org.hibernate.loader.Loader.doQuery(Loader.java:829)
    at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:274)
    at org.hibernate.loader.Loader.doList(Loader.java:2533)
    ... 16 more
{code}

The full stack got chopped at 16... here is the full SQLException...

{code}
The stack trace above got truncated at "16 more" so I set an exception breakpoint on SQLExceptions and captured the full stack of the exception.  That's what tells me it's the CircuitTemplate field descriptions that is causing the problem with enver's AuditReader.
Thread [main] (Suspended (exception java.sql.SQLException))    
    com.mysql.jdbc.JDBC4ResultSet(com.mysql.jdbc.ResultSetImpl).findColumn(java.lang.String) line: 1145    
    com.mysql.jdbc.JDBC4ResultSet(com.mysql.jdbc.ResultSetImpl).getLong(java.lang.String) line: 3022    
    com.mchange.v2.c3p0.impl.NewProxyResultSet.getLong(java.lang.String) line: 2469    
    org.hibernate.type.LongType.get(java.sql.ResultSet, java.lang.String) line: 51    
    org.hibernate.type.LongType(org.hibernate.type.NullableType).nullSafeGet(java.sql.ResultSet, java.lang.String) line: 186    
    org.hibernate.type.LongType(org.hibernate.type.NullableType).nullSafeGet(java.sql.ResultSet, java.lang.String[], org.hibernate.engine.SessionImplementor, java.lang.Object) line: 175    
    org.hibernate.type.ManyToOneType.hydrate(java.sql.ResultSet, java.lang.String[], org.hibernate.engine.SessionImplementor, java.lang.Object) line: 157    
    org.hibernate.type.ComponentType.hydrate(java.sql.ResultSet, java.lang.String[], org.hibernate.engine.SessionImplementor, java.lang.Object) line: 588    
    org.hibernate.type.ComponentType.nullSafeGet(java.sql.ResultSet, java.lang.String[], org.hibernate.engine.SessionImplementor, java.lang.Object) line: 303    
    org.hibernate.type.ManyToOneType.hydrate(java.sql.ResultSet, java.lang.String[], org.hibernate.engine.SessionImplementor, java.lang.Object) line: 157    
    org.hibernate.type.ManyToOneType(org.hibernate.type.EntityType).nullSafeGet(java.sql.ResultSet, java.lang.String[], org.hibernate.engine.SessionImplementor, java.lang.Object) line: 227    
    org.hibernate.loader.hql.QueryLoader.getResultColumnOrRow(java.lang.Object[], org.hibernate.transform.ResultTransformer, java.sql.ResultSet, org.hibernate.engine.SessionImplementor) line: 399    
    org.hibernate.loader.hql.QueryLoader(org.hibernate.loader.Loader).getRowFromResultSet(java.sql.ResultSet, org.hibernate.engine.SessionImplementor, org.hibernate.engine.QueryParameters, org.hibernate.LockMode[], org.hibernate.engine.EntityKey, java.util.List, org.hibernate.engine.EntityKey[], boolean) line: 647    
    org.hibernate.loader.hql.QueryLoader(org.hibernate.loader.Loader).doQuery(org.hibernate.engine.SessionImplementor, org.hibernate.engine.QueryParameters, boolean) line: 745    
    org.hibernate.loader.hql.QueryLoader(org.hibernate.loader.Loader).doQueryAndInitializeNonLazyCollections(org.hibernate.engine.SessionImplementor, org.hibernate.engine.QueryParameters, boolean) line: 270    
    org.hibernate.loader.hql.QueryLoader(org.hibernate.loader.Loader).doList(org.hibernate.engine.SessionImplementor, org.hibernate.engine.QueryParameters) line: 2294    
    org.hibernate.loader.hql.QueryLoader(org.hibernate.loader.Loader).listIgnoreQueryCache(org.hibernate.engine.SessionImplementor, org.hibernate.engine.QueryParameters) line: 2172    
    org.hibernate.loader.hql.QueryLoader(org.hibernate.loader.Loader).list(org.hibernate.engine.SessionImplementor, org.hibernate.engine.QueryParameters, java.util.Set, org.hibernate.type.Type[]) line: 2167    
    org.hibernate.loader.hql.QueryLoader.list(org.hibernate.engine.SessionImplementor, org.hibernate.engine.QueryParameters) line: 448    
    org.hibernate.hql.ast.QueryTranslatorImpl.list(org.hibernate.engine.SessionImplementor, org.hibernate.engine.QueryParameters) line: 363    
    org.hibernate.engine.query.HQLQueryPlan.performList(org.hibernate.engine.QueryParameters, org.hibernate.engine.SessionImplementor) line: 196    
    org.hibernate.impl.SessionImpl.list(java.lang.String, org.hibernate.engine.QueryParameters) line: 1258    
    org.hibernate.impl.QueryImpl.list() line: 102    
    org.hibernate.envers.entities.mapper.relation.lazy.initializor.BasicCollectionInitializor<T>(org.hibernate.envers.entities.mapper.relation.lazy.initializor.AbstractCollectionInitializor<T>).initialize() line: 62    
    org.hibernate.envers.entities.mapper.relation.lazy.proxy.ListProxy<U>(org.hibernate.envers.entities.mapper.relation.lazy.proxy.CollectionProxy<U,T>).checkInit() line: 50    
    org.hibernate.envers.entities.mapper.relation.lazy.proxy.ListProxy<U>(org.hibernate.envers.entities.mapper.relation.lazy.proxy.CollectionProxy<U,T>).iterator() line: 70    
    com.rci.maxview.cm.structure.template.api.CircuitTemplate.getFieldDescriptions() line: 320    
    com.rci.maxview.cm.structure.template.api.CircuitTemplate.toString() line: 670    
    java.lang.String.valueOf(java.lang.Object) line: 2826    
    java.io.PrintStream.println(java.lang.Object) line: 771
{code}

The SQL being generated by Hibernate for the AuditReader query, appears to be

{code:sql}
DEBUG 2011-05-11 17:50:39,394[main](BasicResourcePool.java:1644) - trace com.mchange.v2.resourcepool.BasicResourcePool@15f4a7f [managed: 2, unused: 1, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@14b6b02)
Hibernate: 
    /* select
        new list(ee,
        e) 
    from

        circuit_template_field_descriptions_AUD ee,
        com.rci.maxview.cm.structure.template.api.CircuitTemplateFieldDescription_AUD e 
    where
        ee.originalId.fieldDescriptions_uniqueId = e.originalId.uniqueId 
        and ee.originalId.CircuitTemplate_id = :CircuitTemplate_id 
        and e.originalId.REV.id = (
            select
                max(e2.originalId.REV.id) 
            from
                com.rci.maxview.cm.structure.template.api.CircuitTemplateFieldDescription_AUD e2 
            where
                e2.originalId.REV.id <= :revision 
                and e.originalId.uniqueId = e2.originalId.uniqueId
        ) 
        and ee.originalId.REV.id = (
            select
                max(ee2.originalId.REV.id) 
            from
                circuit_template_field_descriptions_AUD ee2 
            where
                ee2.originalId.REV.id <= :revision 
                and ee.originalId.CircuitTemplate_id = ee2.originalId.CircuitTemplate_id 
                and ee.originalId.fieldDescriptions_uniqueId = ee2.originalId.fieldDescriptions_uniqueId
        ) 
        and ee.REVTYPE != :delrevisiontype 
        and e.REVTYPE != :delrevisiontype */ select
            circuit_te0_.rev as col_0_0_,
            circuit_te0_.circuit_template as col_0_1_,
            circuit_te0_.field_descriptions as col_0_2_,
            circuittem1_.field_index as col_1_0_ 
        from
            mvp_log.circuit_template_field_descriptions_aud circuit_te0_ cross 
        join
            mvp_log.circuit_template_field_description_aud circuittem1_ 
        where
            circuit_te0_.field_descriptions=circuittem1_.unique_id 
            and circuit_te0_.circuit_template=? 
            and circuittem1_.rev=(
                select
                    max(circuittem2_.rev) 
                from
                    mvp_log.circuit_template_field_description_aud circuittem2_ 
                where
                    circuittem2_.rev<=? 
                    and circuittem1_.unique_id=circuittem2_.unique_id
            ) 
            and circuit_te0_.rev=(
                select
                    max(circuit_te3_.rev) 
                from
                    mvp_log.circuit_template_field_descriptions_aud circuit_te3_ 
                where
                    circuit_te3_.rev<=? 
                    and circuit_te0_.circuit_template=circuit_te3_.circuit_template 
                    and circuit_te0_.field_descriptions=circuit_te3_.field_descriptions
            ) 
            and circuit_te0_.revtype<>? 
            and circuittem1_.revtype<>?
Hibernate: 
    /* load circuit_template_field_descriptions_AUD */ select
        circuit_te0_.rev as rev45_0_,
        circuit_te0_.circuit_template as circuit2_45_0_,
        circuit_te0_.field_descriptions as field3_45_0_,
        circuit_te0_.revtype as revtype45_0_ 
    from
        mvp_log.circuit_template_field_descriptions_aud circuit_te0_ 
    where
        circuit_te0_.rev=? 
        and circuit_te0_.circuit_template=? 
        and circuit_te0_.field_descriptions=?
{code:sql}

[buzz3791]

I think this issue is an Envers defect.  In our system we model a system where Circuits have a @OneToMany relationship to Fields.  Envers is having a problem with the Fields code.  Our Field @Entity declares these 2 instance variables:

    @Id

    private String uniqueId;  // the primary key for the Field table

    @Column(name="field_index", nullable=false) // The FieldDescription interface defines getId(), but I want the field to be named more appropriately and avoid reserved keywords in the DB, so I'm naming the column field_index since the field accessor (getId()) must follow the bean convention.

    @Basic(optional=false)

    private short id; // This "id" is the index of the field. It's used by JPA for the retention of list order; it can't be changed.

Fields implements an interface FieldDescription that has a getId method, Hibernate will only use this accessor if we have a instance variable named "id".  However, "id" appears to be a reserved word for JPA, so we use the @Column to make JPA/Hibernate happy.

This issue seems to be related to the Eenvers AuditReader generating invalid HQL an instance variable named "id" but not marked with an @javax.persistence.Id annotation.  Possibly the issue only appears when the "many" side (of the @OneToMany mapping) uses the @Column or has an "id" instance variable not marked with @Id.  Once I deleted the Field.id and all related code, the AuditReader worked fine.

I need the "id" code, so I'm working around thie Envers defect by renaming the accessor in the FieldDescription interface from getId to getIndex.

This issue may be related to "Enver Auditing: Audit Join table is missing columns or behaving incorrectly on a @ManyToOne mapping"

http://opensource.atlassian.com/projects/hibernate/browse/HHH-5482

Should I open a new defect for this issue?

Brian

[adamw]

In HQL, entity.id always referes to the PK of the entity

But there's clearly something wrong. If you could open a bug with an Envers test case (there's a lot of test cases in the source code, so just copy one & edit), it would be great.

Adam