TwoPhaseCoordinator.beforeCompletion - failed for com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple

our application was throwing the following error:
//////////////////////////////////////////////////////////
>30 Nov 2012 11:19:46,671  WARN     com.arjuna.ats.arjuna.logging.arjLoggerI18N                                                    [com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator_2] TwoPhaseCoordinator.beforeCompletion - failed for com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple@2f66531d
javax.persistence.PersistenceException: java.lang.NullPointerException
    at org.hibernate.ejb.AbstractEntityManagerImpl$1.beforeCompletion(AbstractEntityManagerImpl.java:527)
...
Caused by: java.lang.NullPointerException
    at org.hibernate.type.IntegerType.next(IntegerType.java:59)
    at org.hibernate.engine.Versioning.increment(Versioning.java:108)
    at org.hibernate.event.def.DefaultFlushEntityEventListener.getNextVersion(DefaultFlushEntityEventListener.java:365)
...
com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] Can't commit because the transaction is in aborted state
//////////////////////////////////////////////////////////



which was caused after running the following code:
em.merge(anObject);
em.flush(); // this one caused the problem



to better be able to find a clue about the error we had to enable some hibernate logging.

persistence.xml:
####################
<?xml version="1.0" encoding="UTF-8"?>
<persistence xmlns="http://java.sun.com/xml/ns/persistence"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://java.sun.com/xml/ns/persistence http://java.sun.com/xml/ns/persistence/persistence_1_0.xsd"
    version="1.0">
    <persistence-unit name="EJBRelationshipsPU"
        transaction-type="JTA">
        ...
        <properties>
            ...
            <property name="hibernate.show_sql" value="true" />
            ...
        </properties>
    </persistence-unit>
</persistence>
####################


/usr/jboss/server/tcdomain/conf/myApp-jboss-log4j.xml:
####################
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">
...
    <category name="org.hibernate.event.def" additivity="false">
        <priority value="trace"/>
        <appender-ref ref="stdout"/>
    </category>
    <category name="org.hibernate.loader" additivity="false">
        <priority value="trace"/>
        <appender-ref ref="stdout"/>
    </category>
    <category name="org.hibernate" additivity="false">
        <priority value="trace"/>
        <appender-ref ref="stdout"/>
    </category>
...
</log4j:configuration>
####################

we rebuilt the code and restarted the server in debugging. the configuration above will generate TONS of logging output, so to narrow it down we set a breakpoint on the following line:
em.merge(anObject);

then we cleared the console and clicked "Resume". now we could focus on just the relevant error code.



the following log output gave us a better clue about the problem:
//////////////////////////////////////////////////////////
>30 Nov 2012 11:18:47,175  DEBUG    org.hibernate.event.def.AbstractFlushingEventListener                                          dirty checking collections
>30 Nov 2012 11:18:47,176  DEBUG    org.hibernate.engine.CollectionEntry                                                           Collection dirty: [com.myapp.domainentitiesEJB3.transportrequest.TransportRequest.quantitiesAndStatusLogs#153570]
>30 Nov 2012 11:18:47,176  DEBUG    org.hibernate.engine.CollectionEntry                                                           Collection dirty: [com.myapp.domainentitiesEJB3.transportrequest.TransportRequest.trackAndTraceEvents#153570]
>30 Nov 2012 11:18:47,176  TRACE    org.hibernate.event.def.AbstractFlushingEventListener                                          Flushing entities and processing referenced collections
>30 Nov 2012 11:18:47,176  DEBUG    org.hibernate.engine.Collections                                                               Collection found: [com.myapp.domainentitiesEJB3.trackandtrace.TrackAndTraceEvent.action#39023], was: [com.myapp.domainentitiesEJB3.trackandtrace.TrackAndTraceEvent.action#39023] (uninitialized)
>30 Nov 2012 11:18:47,176  DEBUG    org.hibernate.engine.Collections                                                               Collection found: [com.myapp.domainentitiesEJB3.trackandtrace.TrackAndTraceEvent.freeText#39023], was: [com.myapp.domainentitiesEJB3.trackandtrace.TrackAndTraceEvent.freeText#39023] (uninitialized)
>30 Nov 2012 11:18:47,176  TRACE    org.hibernate.persister.entity.AbstractEntityPersister                                         com.myapp.domainentitiesEJB3.transportrequest.TransportRequest.version is dirty
>30 Nov 2012 11:18:47,176  TRACE    org.hibernate.persister.entity.AbstractEntityPersister                                         com.myapp.domainentitiesEJB3.transportrequest.TransportRequest.versionnumber is dirty
//////////////////////////////////////////////////////////


we checked out everything mentioned here and it seemed fine, but when we checked the versionnumber field in the database table for TRANSPORT_REQUEST it was null. versionnumber is what hibernate uses for versioning in the entity. so we set it to 1 and then everything worked fine!

what happened was that row had been created a long time ago before we switched to ejb3 so it didn't have a value, it was null.

thanks to my colleague Dan for much help in resolving this issue! :)