search

kumuluz / kumuluzee

Lightweight open-source framework for developing microservices using standard Java EE technologies and migrating Java EE to cloud-native architecture.
https://ee.kumuluz.com
MIT License
291 stars 71 forks source link

Rollback is not happening when changes are flushed #128

Closed Mulgish closed 4 years ago

Mulgish commented 5 years ago

When I flush any changes to the db, it never rolls back.

Sample code

@RequestScoped
public class TestRollback {

    @PersistenceContext(unitName = "syrup")
    private EntityManager entityManager;

    @Transactional(value = Transactional.TxType.REQUIRES_NEW, rollbackOn = Exception.class)
    public void addTest() throws Exception {
        System.out.println("~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ NATIVE QUERY BEGIN");

        //THis won't rollback
        final Query nativeQuery = entityManager.createNativeQuery("insert into public.testrollback (mytext) values ('" + ZonedDateTime.now().toString() + "')");
        nativeQuery.executeUpdate();

          //This will rollback
//        final TestEntity o = new TestEntity();
//        o.setTestMessage(ZonedDateTime.now().toString());
//        o.setId(UUID.randomUUID().toString());
//        entityManager.persist(o);

        throw new Exception("Testing Rollback");
    }

}

Logs:

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~NATIVE QUERY LOG~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
2018-12-13 16:38:51.942 INFO -- com.kumuluz.ee.EeApplication -- KumuluzEE started successfully
2018-12-13 16:39:08.107 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.begin
2018-12-13 16:39:08,135 INFO  ARJUNA012170: TransactionStatusManager started on port 51041 and host 127.0.0.1 with service com.arjuna.ats.arjuna.recovery.ActionStatusService {}
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ NATIVE QUERY BEGIN
2018-12-13 16:39:08.146 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2018-12-13 16:39:08.148 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.registerSynchronization - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization HashCode: 508082975 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@1e48bb1f
2018-12-13 16:39:08.176 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2018-12-13 16:39:08.178 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2018-12-13 16:39:08.179 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2018-12-13 16:39:08.191 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
Hibernate: insert into public.testrollback (mytext) values ('2018-12-13T16:39:08.145959Z[Europe/London]')
2018-12-13 16:39:08.205 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2018-12-13 16:39:08.206 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.setRollbackOnly
2018-12-13 16:39:08.207 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_MARKED_ROLLBACK
2018-12-13 16:39:08.207 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.rollback
2018-12-13 16:39:08.207 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.rollbackAndDisassociate
2018-12-13 16:39:08.208 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.afterCompletion - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization HashCode: 508082975 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@1e48bb1f
2018-12-13 16:39:08,223 INFO  Session Metrics {
    615925 nanoseconds spent acquiring 1 JDBC connections;
    13220 nanoseconds spent releasing 1 JDBC connections;
    4541016 nanoseconds spent preparing 1 JDBC statements;
    3769157 nanoseconds spent executing 1 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections);
   29745 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections)
} {}

2018-12-13 16:39:08.225 WARNING -- org.eclipse.jetty.server.HttpChannel -- /rest/sample/roll
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~JPA QUERY LOG~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

2018-12-13 16:51:00.538 INFO -- com.kumuluz.ee.EeApplication -- KumuluzEE started successfully
2018-12-13 16:51:02.757 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.begin
2018-12-13 16:51:02,790 INFO  ARJUNA012170: TransactionStatusManager started on port 52001 and host 127.0.0.1 with service com.arjuna.ats.arjuna.recovery.ActionStatusService {}
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ JPA QUERY BEGIN
2018-12-13 16:51:02.808 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2018-12-13 16:51:02.810 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.registerSynchronization - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization HashCode: 1848796389 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@6e3264e5
2018-12-13 16:51:02.821 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2018-12-13 16:51:02.837 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.setRollbackOnly
2018-12-13 16:51:02.838 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_MARKED_ROLLBACK
2018-12-13 16:51:02.839 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.rollback
2018-12-13 16:51:02.839 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.rollbackAndDisassociate
2018-12-13 16:51:02.840 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.afterCompletion - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization HashCode: 1848796389 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@6e3264e5
2018-12-13 16:51:02,859 INFO  Session Metrics {
    0 nanoseconds spent acquiring 0 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    0 nanoseconds spent preparing 0 JDBC statements;
    0 nanoseconds spent executing 0 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
} {}
2018-12-13 16:51:02.860 WARNING -- org.eclipse.jetty.server.HttpChannel -- /rest/sample/roll
javax.servlet.ServletException: org.glassfish.jersey.server.ContainerException: java.lang.Exception: Testing Rollback

persistence.xml

<?xml version="1.0" encoding="UTF-8" ?>
<persistence xmlns="http://xmlns.jcp.org/xml/ns/persistence"
             xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
             xsi:schemaLocation="http://xmlns.jcp.org/xml/ns/persistence
             http://xmlns.jcp.org/xml/ns/persistence/persistence_2_1.xsd"
             version="2.1">
    <persistence-unit name="syrup" transaction-type="JTA">
        <jta-data-source>java:/postgres</jta-data-source>
        <class>com.test.TestEntity</class>
        <exclude-unlisted-classes>false</exclude-unlisted-classes>

        <properties>
            <property name="hibernate.connection.autocommit" value="false"/>
            <property name="hibernate.dialect" value="org.hibernate.dialect.PostgreSQL9Dialect"/>
            <property name="hibernate.hbm2ddl.auto" value="validate"/>
            <property name="hibernate.show_sql" value="true"/>
            <property name="hibernate.generate_statistics" value="true"/>
        </properties>
    </persistence-unit>
</persistence>

Data source

  {
        "jndi-name": "java:/postgres",
        "driver-class": "org.postgresql.Driver",
        "connection-url": "jdbc:postgresql://localhost:5432/test",
        "username": "xxxx",
        "password": "xxxx",
        "max-pool-size": 20
      }

Dependencies

       <dependency>
            <groupId>com.kumuluz.ee</groupId>
            <artifactId>kumuluzee-microProfile-1.2</artifactId>
        </dependency>
        <dependency>
            <groupId>com.kumuluz.ee</groupId>
            <artifactId>kumuluzee-jta-narayana</artifactId>
        </dependency>
        <dependency>
            <groupId>com.kumuluz.ee</groupId>
            <artifactId>kumuluzee-jpa-hibernate</artifactId>
        </dependency>
Mulgish commented 5 years ago

Just noticed that rollback won't happen even for JPA query when I flush the changes.

@RequestScoped
public class TestRollback {

    @PersistenceContext(unitName = "syrup")
    private EntityManager entityManager;

    @Transactional(value = Transactional.TxType.REQUIRES_NEW, rollbackOn = Exception.class)
    public void addTest() throws Exception {
        final TestEntity o = new TestEntity();
        o.setTestMessage(ZonedDateTime.now().toString());
        o.setId(UUID.randomUUID().toString());
        entityManager.persist(o);

        //This will prevent rollback
        entityManager.flush();

        throw new Exception("Testing Rollback");
    }

}
2018-12-14 09:18:21.633 INFO -- com.kumuluz.ee.EeApplication -- KumuluzEE started successfully
2018-12-14 09:18:35.448 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.begin
2018-12-14 09:18:35,479 INFO  ARJUNA012170: TransactionStatusManager started on port 52420 and host 127.0.0.1 with service com.arjuna.ats.arjuna.recovery.ActionStatusService {}
2018-12-14 09:18:35.493 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2018-12-14 09:18:35.494 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.registerSynchronization - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization HashCode: 1219096433 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@48a9ef71
2018-12-14 09:18:35.500 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2018-12-14 09:18:35.517 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
Hibernate: insert into TestEntity (testMessage, id) values (?, ?)
2018-12-14 09:18:35.553 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.setRollbackOnly
2018-12-14 09:18:35.553 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_MARKED_ROLLBACK
2018-12-14 09:18:35.553 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.rollback
2018-12-14 09:18:35.554 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.rollbackAndDisassociate
2018-12-14 09:18:35.554 INFO -- com.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.afterCompletion - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization HashCode: 1219096433 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@48a9ef71
2018-12-14 09:18:35,570 INFO  Session Metrics {
    567552 nanoseconds spent acquiring 1 JDBC connections;
    17125 nanoseconds spent releasing 1 JDBC connections;
    4792794 nanoseconds spent preparing 1 JDBC statements;
    0 nanoseconds spent executing 0 JDBC statements;
    5208919 nanoseconds spent executing 1 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    35082759 nanoseconds spent executing 1 flushes (flushing a total of 1 entities and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
} {}
2018-12-14 09:18:35.572 WARNING -- org.eclipse.jetty.server.HttpChannel -- /rest/sample/roll
javax.servlet.ServletException: org.glassfish.jersey.server.ContainerException: java.lang.Exception: Testing Rollback
Mulgish commented 5 years ago

Hi, Do you have an update on the issue? I managed to reproduce it with clean PostgreSQL 11 installation and kumuluzee-jpa example project.

urbim commented 5 years ago

Hi!

I looked into this issue some time ago, but couldn't find the cause of the problem. Unfortunately since then, I haven't found the time to dig deeper into it.

Maybe @salvadormarcos can help since he was the original author of the JTA extension?

salvadormarcos commented 5 years ago

Hello @Mulgikapsas,

I have done some tests and the cause of the problem is the type of DataSource that you are using. JTA transactions are available only with XADataSource.

Could you repeat your test using this XADataSource configuration? You can see an example configuration at this link https://github.com/kumuluz/kumuluzee/wiki/EeConfig

@urbim The other Transaction Managers (Atomikos and Bitronix) have their own pool of connections. In contrast, Narayana relies on an external connection pool that provides an XADataSource.

JBoss is working on Agroal, a connection pool with native integration with Narayana. It was inserted into the Wildfly 14 as an alternative to the traditional connection pool. In a future release, it may be to make the pool default. http://wildfly.org/news/2018/08/30/WildFly14-Final-Released/

In the future, perhaps a possible integration with Agroal could improve the JTA extension and avoid problems like this.

urbim commented 5 years ago

@salvadormarcos Thanks for the explanation!

Yes, the Agroal project definitely looks promising. However to integrate it in our framework, we would first need to modularize the connection pool in our framework. We want to keep the Hikari pool in the framework mainly for its speed, but alternatives would definitely be welcome.

Mulgish commented 5 years ago

@salvadormarcos I can confirm that the issue is now resolved. It is a bit strange though that we have to use XA data source for a single db.

salvadormarcos commented 5 years ago

@Mulgikapsas Yes, this really sounds strange. However, JTA transacts only objects derived from XADataSource or XAResource. Pools of connections that allow transactions in standard Datasource create a "Fake XADataSource" to work with JTA.

@urbim Great! Agroal's proposal is precisely to be a pool of high performance connections.

The best part of this is that it provides an implementation with Hikari wrapped and another with Agroal's own transactional pool. In this way, there would be no need to modularize the pool of connections. It would be enough just select the implementation of the pool..

I imagine that in a possible implementation, the default would be to use Hikari wrapped as implementation. When there is the extension of the JTA (Narayana) present, the implementation would be the Agroal.

If you want to take a look at the project, Agroal's repository is https://github.com/agroal/agroal

urbim commented 5 years ago

@salvadormarcos That's an interesting proposal. Yes, I guess we could bring in the agroal-api dependency to the core and then include the agroal-hikari in the jpa component and agroal-pool in the jta component. The only problem I see in this setup is the unnecessary inclusion of Hikari when using jpa + jta components. But I guess this is simpler and more elegant than the other option where the user has to explicitly specify the connection pool implementation in the dependencies.

salvadormarcos commented 5 years ago

@urbim I think it would be better to also add "agroal-hikari" to the core than in the JPA component. If the user used pure JDBC or another ORM framework, Hikari's DataSource would still be available.

By the way, a while ago I sent a PR about IronJacamar and JCA support. Currently, I believe that it makes more sense for three reasons:

  1. This possible adoption of Agroal improves integration with JTA;
  2. Other facilities provided by the JCA are dependent on the EJB. For example, we can not use annotations such as javax.ejb.MessageDriven or javax.ejb.ActivationConfigProperty and IronJacamar does not provide any APIs to emulate these annotations.
  3. The IronJacamar settings (DataSources, WorkManager, etc) are made by XML files. The only way to get around this is by using ShrinkWrap, which is also a dependency of IronJacamar itself. The result was really complex and brings several extra dependencies to the project.

For these reasons, I believe that this PR could be discarded.

Mulgish commented 5 years ago

Hi, I am getting new errors when I persist a bit more complex entities and use XA data source. This issue is not reproducible when I use normal data source.

Base entity:

@MappedSuperclass
public class BaseEntity implements VersionedEntity {
    @Id
    @SequenceGenerator(name = "SEQ_GEN_ID", sequenceName = "public.hibernate_sequence")
    @GeneratedValue(strategy = GenerationType.SEQUENCE, generator = "SEQ_GEN_ID")
    protected Long id;
    @Version
    protected Long version;

    public Long getId() {
        return id;
    }

    public void setId(final Long id) {
        this.id = id;
    }

    public Long getVersion() {
        return version;
    }

    public void setVersion(final Long version) {
        this.version = version;
    }
}

Timestamp entity:

@MappedSuperclass
public class BaseTimestampedEntity extends BaseEntity {
    protected LocalDateTime createdTimestamp;
    protected LocalDateTime updatedTimestamp;

    public LocalDateTime getCreatedTimestamp() {
        return createdTimestamp;
    }

    public void setCreatedTimestamp(final LocalDateTime createdTimestamp) {
        this.createdTimestamp = createdTimestamp;
    }

    public LocalDateTime getUpdatedTimestamp() {
        return updatedTimestamp;
    }

    public void setUpdatedTimestamp(final LocalDateTime updatedTimestamp) {
        this.updatedTimestamp = updatedTimestamp;
    }
}

Entity 1:

@Entity
public class TestEntity extends BaseTimestampedEntity {
    @OneToMany(mappedBy = "testEntity", cascade = CascadeType.ALL, orphanRemoval = true, fetch = FetchType.EAGER)
    private List<ChildTestEntity> childTestEntities = new ArrayList<>();
    private String payload;

    /**
     * Get payload.
     **/
    public String getPayload() {
        return payload;
    }

    /**
     * Sets the payload and returns a reference to this for chaining.
     **/
    public TestEntity setPayload(final String payload) {
        this.payload = payload;
        return this;
    }

    /**
     * Get childTestEntities.
     **/
    public List<ChildTestEntity> getChildTestEntities() {
        return childTestEntities;
    }
}

Entity 2

@Entity
public class ChildTestEntity extends BaseTimestampedEntity {

    @ManyToOne
    @JoinColumn(name = "testEntityId")
    private TestEntity testEntity;

    private String payload;

    /**
     * Get payload.
     **/
    public String getPayload() {
        return payload;
    }

    /**
     * Sets the payload and returns a reference to this for chaining.
     **/
    public ChildTestEntity setPayload(final String payload) {
        this.payload = payload;
        return this;
    }

    /**
     * Get testEntity.
     **/
    public TestEntity getTestEntity() {
        return testEntity;
    }

    /**
     * Sets the testEntity.
     **/
    public void setTestEntity(final TestEntity testEntity) {
        this.testEntity = testEntity;
    }
}

Code:


@RequestScoped
public class TestRollback {

    @PersistenceContext(unitName = "syrup")
    private EntityManager entityManager;

    @Transactional(value = Transactional.TxType.REQUIRES_NEW, rollbackOn = Exception.class)
    public void addTest() {
        final TestEntity testEntity = new TestEntity();
        testEntity.setPayload("I am test entity " + ZonedDateTime.now().toString());

        for (int i = 0; i < 3; i++) {
            final ChildTestEntity childTestEntity = new ChildTestEntity();
            childTestEntity.setTestEntity(testEntity);
            childTestEntity.setPayload("I am child of test entity. No: " + i);
            testEntity.getChildTestEntities().add(childTestEntity);
        }
        entityManager.persist(testEntity);
    }

}

Log without XA data source:

2019-02-25 15:52:57.351 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.begin
2019-02-25 15:52:57,387 INFO  ARJUNA012170: TransactionStatusManager started on port 55602 and host 127.0.0.1 with service com.arjuna.ats.arjuna.recovery.ActionStatusService {}
2019-02-25 15:52:57.399 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:52:57.400 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.registerSynchronization - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSyn
chronization HashCode: 476845270 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@1c6c14d6
Hibernate: select nextval ('public.hibernate_sequence')
Hibernate: select nextval ('public.hibernate_sequence')
2019-02-25 15:52:57.433 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
Hibernate: select nextval ('public.hibernate_sequence')
2019-02-25 15:52:57.455 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:52:57.457 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:52:57.457 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:52:57.458 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:52:57.458 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.commit
2019-02-25 15:52:57.459 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.commitAndDisassociate
2019-02-25 15:52:57.459 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.beforeCompletion - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchr
onization HashCode: 476845270 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@1c6c14d6
2019-02-25 15:52:57.461 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
Hibernate: insert into TestEntity (version, createdTimestamp, updatedTimestamp, payload, id) values (?, ?, ?, ?, ?)
Hibernate: insert into ChildTestEntity (version, createdTimestamp, updatedTimestamp, payload, testEntityId, id) values (?, ?, ?, ?, ?, ?)
Hibernate: insert into ChildTestEntity (version, createdTimestamp, updatedTimestamp, payload, testEntityId, id) values (?, ?, ?, ?, ?, ?)
Hibernate: insert into ChildTestEntity (version, createdTimestamp, updatedTimestamp, payload, testEntityId, id) values (?, ?, ?, ?, ?, ?)
2019-02-25 15:52:57.528 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.afterCompletion - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchro
nization HashCode: 476845270 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@1c6c14d6
2019-02-25 15:52:57,541 INFO  Session Metrics {
    838295 nanoseconds spent acquiring 4 JDBC connections;
    39360 nanoseconds spent releasing 4 JDBC connections;
    3811088 nanoseconds spent preparing 7 JDBC statements;
    12161592 nanoseconds spent executing 7 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    66385472 nanoseconds spent executing 1 flushes (flushing a total of 4 entities and 1 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
} {}

Database: image image

Logs with XA data source:

2019-02-25 15:55:38,865 INFO  ARJUNA012170: TransactionStatusManager started on port 55819 and host 127.0.0.1 with service com.arjuna.ats.arjuna.recovery.ActionStatusService {}
2019-02-25 15:55:38.881 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:38.882 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.registerSynchronization - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSyn
chronization HashCode: 177222822 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@a9034a6
Hibernate: select nextval ('public.hibernate_sequence')
2019-02-25 15:55:39.046 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.047 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.enlistResource ( org.postgresql.xa.PGXAConnection@1ae3af5f )
2019-02-25 15:55:39.048 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.053 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerXAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0acc202c:da0c:5c740ffa:2, node_name=1,
branch_uid=0:ffff0acc202c:da0c:5c740ffa:4, subordinatenodename=null, eis_name=0 >, org.postgresql.xa.PGXAConnection@1ae3af5f ), record id=0:ffff0acc202c:da0c:5c740ffa:5
2019-02-25 15:55:39.057 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.registerSynchronization - Class: class com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1 HashCode: 717966877 to
String: com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1@2acb4e1d
Hibernate: select nextval ('public.hibernate_sequence')
2019-02-25 15:55:39.243 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.244 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.enlistResource ( org.postgresql.xa.PGXAConnection@4180e45 )
2019-02-25 15:55:39.244 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.245 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerXAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0acc202c:da0c:5c740ffa:2, node_name=1,
branch_uid=0:ffff0acc202c:da0c:5c740ffa:8, subordinatenodename=null, eis_name=0 >, org.postgresql.xa.PGXAConnection@4180e45 ), record id=0:ffff0acc202c:da0c:5c740ffa:9
2019-02-25 15:55:39.248 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.registerSynchronization - Class: class com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1 HashCode: 1055858794 t
oString: com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1@3eef206a
2019-02-25 15:55:39.252 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
Hibernate: select nextval ('public.hibernate_sequence')
2019-02-25 15:55:39.420 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.421 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.enlistResource ( org.postgresql.xa.PGXAConnection@784abdcf )
2019-02-25 15:55:39.422 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.423 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerXAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0acc202c:da0c:5c740ffa:2, node_name=1,
branch_uid=0:ffff0acc202c:da0c:5c740ffa:c, subordinatenodename=null, eis_name=0 >, org.postgresql.xa.PGXAConnection@784abdcf ), record id=0:ffff0acc202c:da0c:5c740ffa:d
2019-02-25 15:55:39.424 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.registerSynchronization - Class: class com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1 HashCode: 2009830326 t
oString: com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1@77cb93b6
2019-02-25 15:55:39.426 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.428 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.429 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.430 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.431 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.commit
2019-02-25 15:55:39.431 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.commitAndDisassociate
2019-02-25 15:55:39.432 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.beforeCompletion - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchr
onization HashCode: 177222822 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@a9034a6
2019-02-25 15:55:39.432 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
Hibernate: insert into TestEntity (version, createdTimestamp, updatedTimestamp, payload, id) values (?, ?, ?, ?, ?)
2019-02-25 15:55:39.602 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.603 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.enlistResource ( org.postgresql.xa.PGXAConnection@1d6a76c6 )
2019-02-25 15:55:39.603 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.604 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerXAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0acc202c:da0c:5c740ffa:2, node_name=1,
branch_uid=0:ffff0acc202c:da0c:5c740ffa:10, subordinatenodename=null, eis_name=0 >, org.postgresql.xa.PGXAConnection@1d6a76c6 ), record id=0:ffff0acc202c:da0c:5c740ffa:11
2019-02-25 15:55:39.605 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.registerSynchronization - Class: class com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1 HashCode: 1542973905 t
oString: com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1@5bf7e9d1
Hibernate: insert into ChildTestEntity (version, createdTimestamp, updatedTimestamp, payload, testEntityId, id) values (?, ?, ?, ?, ?, ?)
2019-02-25 15:55:39.627 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2019-02-25 15:55:39.628 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.setRollbackOnly
2019-02-25 15:55:39.629 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.setRollbackOnly
2019-02-25 15:55:39,629 ERROR  HHH000346: Error during managed flush [null] {}
2019-02-25 15:55:39.630 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerBaseTransaction.setRollbackOnly
2019-02-25 15:55:39.630 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerTransactionImple.setRollbackOnly
2019-02-25 15:55:39,631 WARN  ARJUNA012125: TwoPhaseCoordinator.beforeCompletion - failed for SynchronizationImple< 0:ffff0acc202c:da0c:5c740ffa:3, org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@a9034a6 > {} java.l
ang.reflect.UndeclaredThrowableException
        at com.sun.proxy.$Proxy146.executeUpdate(Unknown Source)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175)
        at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3171)
        at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3686)
        at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:90)
        at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
        at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478)
        at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356)
        at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
        at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1454)
        at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:511)
        at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3283)
        at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2479)
        at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473)
        at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:352)
        at org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
        at org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37)
        at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:360)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
        at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1288)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:232)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:178)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequiresNew.doIntercept(TransactionalInterceptorRequiresNew.java:60)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:88)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequiresNew.intercept(TransactionalInterceptorRequiresNew.java:47)
        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.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
        at com.test.test.rollbackkumuluzee.domain.service.TestRollback$Proxy$_$$_WeldSubclass.addTest(Unknown Source)
        at com.test.test.rollbackkumuluzee.domain.service.TestRollback$Proxy$_$$_WeldClientProxy.addTest(Unknown Source)
        at com.test.test.rollbackkumuluzee.boundary.rest.SampleRESTService.roll(SampleRESTService.java:31)
        at com.test.test.rollbackkumuluzee.boundary.rest.SampleRESTService$Proxy$_$$_WeldSubclass.roll$$super(Unknown Source)
        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.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.proceedInternal(TerminalAroundInvokeInvocationContext.java:51)
        at org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:78)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInNoTx(TransactionalInterceptorBase.java:195)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorNotSupported.doIntercept(TransactionalInterceptorNotSupported.java:60)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:88)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorNotSupported.intercept(TransactionalInterceptorNotSupported.java:47)
        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.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
        at com.test.test.rollbackkumuluzee.boundary.rest.SampleRESTService$Proxy$_$$_WeldSubclass.roll(Unknown Source)
        at com.test.test.rollbackkumuluzee.boundary.rest.SampleRESTService$Proxy$_$$_WeldClientProxy.roll(Unknown Source)
        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.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
        at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:200)
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
        at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
        at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
        at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
        at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
        at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416)
        at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370)
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389)
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342)
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:867)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1623)
        at com.kumuluz.ee.common.filters.PoweredByFilter.doFilter(PoweredByFilter.java:43)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.Server.handle(Server.java:502)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.reflect.InvocationTargetException
        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 com.kumuluz.ee.jta.common.datasources.XAStatementProxy.invoke(XAStatementProxy.java:65)
        ... 118 more
Caused by: org.postgresql.util.PSQLException: ERROR: insert or update on table "childtestentity" violates foreign key constraint "fkh12u8neqqjld1c0y9q8dp7deq"
  Detail: Key (testentityid)=(1) is not present in table "testentity".
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2440)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2183)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:308)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:143)
        at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:120)
        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.postgresql.ds.PGPooledConnection$StatementHandler.invoke(PGPooledConnection.java:428)
        at com.sun.proxy.$Proxy145.executeUpdate(Unknown Source)
        ... 123 more

2019-02-25 15:55:39.666 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerXAResourceRecord.topLevelAbort for XAResourceRecord < resource:org.postgresql.xa.PGXAConnection@1ae3af5f, txid:< formatId=131077, gtrid_lengt
h=29, bqual_length=36, tx_uid=0:ffff0acc202c:da0c:5c740ffa:2, node_name=1, branch_uid=0:ffff0acc202c:da0c:5c740ffa:4, subordinatenodename=null, eis_name=0 >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@3952
d95b >, record id=0:ffff0acc202c:da0c:5c740ffa:5
2019-02-25 15:55:39.667 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerXAResourceRecord.topLevelAbort for XAResourceRecord < resource:org.postgresql.xa.PGXAConnection@4180e45, txid:< formatId=131077, gtrid_length
=29, bqual_length=36, tx_uid=0:ffff0acc202c:da0c:5c740ffa:2, node_name=1, branch_uid=0:ffff0acc202c:da0c:5c740ffa:8, subordinatenodename=null, eis_name=0 >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@35727
376 >, record id=0:ffff0acc202c:da0c:5c740ffa:9
2019-02-25 15:55:39.668 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerXAResourceRecord.topLevelAbort for XAResourceRecord < resource:org.postgresql.xa.PGXAConnection@784abdcf, txid:< formatId=131077, gtrid_lengt
h=29, bqual_length=36, tx_uid=0:ffff0acc202c:da0c:5c740ffa:2, node_name=1, branch_uid=0:ffff0acc202c:da0c:5c740ffa:c, subordinatenodename=null, eis_name=0 >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@3edd
25cb >, record id=0:ffff0acc202c:da0c:5c740ffa:d
2019-02-25 15:55:39.669 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerXAResourceRecord.topLevelAbort for XAResourceRecord < resource:org.postgresql.xa.PGXAConnection@1d6a76c6, txid:< formatId=131077, gtrid_lengt
h=29, bqual_length=36, tx_uid=0:ffff0acc202c:da0c:5c740ffa:2, node_name=1, branch_uid=0:ffff0acc202c:da0c:5c740ffa:10, subordinatenodename=null, eis_name=0 >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@66b
236a6 >, record id=0:ffff0acc202c:da0c:5c740ffa:11
2019-02-25 15:55:39.672 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.afterCompletion - Class: class com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1 HashCode: 1542973905 toStr
ing: com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1@5bf7e9d1
2019-02-25 15:55:39.676 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.afterCompletion - Class: class com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1 HashCode: 2009830326 toStr
ing: com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1@77cb93b6
2019-02-25 15:55:39.678 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.afterCompletion - Class: class com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1 HashCode: 1055858794 toStr
ing: com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1@3eef206a
2019-02-25 15:55:39.680 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.afterCompletion - Class: class com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1 HashCode: 717966877 toStri
ng: com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper$1@2acb4e1d
2019-02-25 15:55:39.683 INFO -- com.test.test.rollbackkumuluzee.boundary.rest.RESTApplication$1 -- org.jboss.logging.LoggerSynchronizationImple.afterCompletion - Class: class org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchro
nization HashCode: 177222822 toString: org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization@a9034a6
2019-02-25 15:55:39,709 INFO  Session Metrics {
    611618412 nanoseconds spent acquiring 4 JDBC connections;
    13822 nanoseconds spent releasing 4 JDBC connections;
    652954480 nanoseconds spent preparing 5 JDBC statements;
    13518186 nanoseconds spent executing 5 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    194006459 nanoseconds spent executing 1 flushes (flushing a total of 4 entities and 1 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
} {}
2019-02-25 15:55:39.715 WARNING -- org.eclipse.jetty.server.HttpChannel -- /swagger-api/swagger-ui/roll
javax.servlet.ServletException: org.glassfish.jersey.server.ContainerException: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
        at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:432)
        at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370)
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389)
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342)
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:867)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1623)
        at com.kumuluz.ee.common.filters.PoweredByFilter.doFilter(PoweredByFilter.java:43)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.Server.handle(Server.java:502)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
        at java.lang.Thread.run(Thread.java:745)
Caused by: org.glassfish.jersey.server.ContainerException: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
        at org.glassfish.jersey.servlet.internal.ResponseWriter.rethrow(ResponseWriter.java:278)
        at org.glassfish.jersey.servlet.internal.ResponseWriter.failure(ResponseWriter.java:260)
        at org.glassfish.jersey.server.ServerRuntime$Responder.process(ServerRuntime.java:460)
        at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:285)
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
        at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
        at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256)
        at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703)
        at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416)
        ... 32 more
Caused by: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1300)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:232)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:178)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequiresNew.doIntercept(TransactionalInterceptorRequiresNew.java:60)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:88)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequiresNew.intercept(TransactionalInterceptorRequiresNew.java:47)
        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.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
        at com.test.test.rollbackkumuluzee.domain.service.TestRollback$Proxy$_$$_WeldSubclass.addTest(Unknown Source)
        at com.test.test.rollbackkumuluzee.domain.service.TestRollback$Proxy$_$$_WeldClientProxy.addTest(Unknown Source)
        at com.test.test.rollbackkumuluzee.boundary.rest.SampleRESTService.roll(SampleRESTService.java:31)
        at com.test.test.rollbackkumuluzee.boundary.rest.SampleRESTService$Proxy$_$$_WeldSubclass.roll$$super(Unknown Source)
        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.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.proceedInternal(TerminalAroundInvokeInvocationContext.java:51)
        at org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:78)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInNoTx(TransactionalInterceptorBase.java:195)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorNotSupported.doIntercept(TransactionalInterceptorNotSupported.java:60)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:88)
        at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorNotSupported.intercept(TransactionalInterceptorNotSupported.java:47)
        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.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
        at com.test.test.rollbackkumuluzee.boundary.rest.SampleRESTService$Proxy$_$$_WeldSubclass.roll(Unknown Source)
        at com.test.test.rollbackkumuluzee.boundary.rest.SampleRESTService$Proxy$_$$_WeldClientProxy.roll(Unknown Source)
        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.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76)
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148)
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191)
        at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:200)
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103)
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493)
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415)
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104)
        at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277)
        ... 41 more
Caused by: java.lang.reflect.UndeclaredThrowableException
        at com.sun.proxy.$Proxy146.executeUpdate(Unknown Source)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175)
        at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3171)
        at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3686)
        at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:90)
        at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
        at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478)
        at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356)
        at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
        at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1454)
        at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:511)
        at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3283)
        at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2479)
        at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473)
        at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:352)
        at org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
        at org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37)
        at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:360)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
        at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1288)
        ... 96 more
Caused by: java.lang.reflect.InvocationTargetException
        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 com.kumuluz.ee.jta.common.datasources.XAStatementProxy.invoke(XAStatementProxy.java:65)
        ... 118 more
Caused by: org.postgresql.util.PSQLException: ERROR: insert or update on table "childtestentity" violates foreign key constraint "fkh12u8neqqjld1c0y9q8dp7deq"
  Detail: Key (testentityid)=(1) is not present in table "testentity".
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2440)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2183)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:308)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:143)
        at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:120)
        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.postgresql.ds.PGPooledConnection$StatementHandler.invoke(PGPooledConnection.java:428)
        at com.sun.proxy.$Proxy145.executeUpdate(Unknown Source)
        ... 123 more

XA and non XA data source configurations:

  "xa-datasources": [
    {
      "jndi-name": "jdbc/postgres11",
      "xa-datasource-class": "org.postgresql.xa.PGXADataSource",
      "username": "xxxx",
      "password": "xxxx",
      "props": {
        "server-name": "localhost",
        "port-number": "5432",
        "database-name": "postgres"
      }
      ]
    "datasources": [
    {
      "jndi-name": "jdbc/postgres11",
      "driver-class": "org.postgresql.Driver",
      "connection-url": "jdbc:postgresql://localhost:5432/postgres",
      "username": "xxx",
      "password": "xxx",
    }
    ]

Everything else is same as before.

Mulgish commented 5 years ago

Hi, Did you manage to reproduce the issue?

cen1 commented 5 years ago

Have you tried using deferred constraints?

Mulgish commented 5 years ago

Same example works perfectly fine in Thorntail. All tables were generated by hibernate, so I think there is something wrong with JTA/JPA.

salvadormarcos commented 5 years ago

@Mulgikapsas Yes, I managed to reproduce the issue. I even tested it with EclipseLink and the problem occurs in both JPA providers. Unfortunately I could not identify the cause of the problem.

I did some testing with Agroal on the project and then everything works as it should in both JPA implementations. This behavior leads me to believe that the problem is in integrating JTA with XaDatasources.

@urbim Can I work in a PR including Agroal as we talked before? With this addition, several classes related to XaDatasources would no longer make sense. I think of marking these classes with @Deprecated. During code review, if you agree, you can remove these classes from the project.

urbim commented 5 years ago

@salvadormarcos That's great to hear! Yes, if you could submit a PR that would be great. Yes, mark them as deprecated for now an we will remove them if needed in the review process.

urbim commented 5 years ago

@Mulgikapsas Hi! We have made some fixes to the existing JTA integration. I've tried your sample and it seems to be working correctly. Can you test if the issue is still present on version 3.4.0-SNAPSHOT?

Mulgish commented 5 years ago

Hi @urbim ,

I will try it out today.

Mulgish commented 5 years ago

Hi @urbim ,

Persist seems to be working now. I had to set max_prepared_transactions = 64 in postgresql.conf to fix new exceptions.

salvadormarcos commented 5 years ago

@urbim I found the following Hikari settings, which so far, do not exist in Agroal:

maxLifetime
name
initializationFailTimeout
isolateInternalQueries
allowPoolSuspension
readOnly
registerMbeans
minIdle

How should I proceed? Do I remove these properties?

urbim commented 5 years ago

@salvadormarcos No, for now deprecation warning should be logged if unused property is defined and we will remove them at a later release.

We will have to schedule the Agroal inclusion for a 4.0.0 release, since it's a breaking change.

salvadormarcos commented 5 years ago

@urbim I finalized an implementation of PR on an Agroal inclusion.

As you have previously suggested, the "agroal-pool" artifact should depend on the JTA module. However, during implementation, I realized that Kumuluz provides XaDataSources independent of the presence of the JTA module. With this change, these datasources would be available only if the JTA was present.

To avoid further problems I found it best to put the artifacts "agroal-pool", "agroal-Hikari" and "agroal-api" as dependence of the Common module (same place where HikariCP was).

Is it okay to submit the code this way? Or should I send as you suggested earlier?

bachmankobts commented 5 years ago

Hello,

if it is true, that the JTA transactions require XA datasource in kumuluz, then this kumuluz example is wrong, because it uses a NON-XA datasource with the JTA:

https://github.com/kumuluz/kumuluzee-samples/tree/master/kumuluzee-rest

kumuluzee:
  datasources:
    - jndi-name: jdbc/CustomersDS
      connection-url: jdbc:postgresql://localhost:5432/customers
      username: postgres
      password: postgres
      pool:
        max-size: 20
<persistence-unit name="kumuluzee-samples-jpa" transaction-type="JTA">
        <jta-data-source>jdbc/CustomersDS</jta-data-source>
        <class>com.kumuluz.ee.samples.rest.Customer</class>
        <properties>
            <property name="javax.persistence.schema-generation.database.action" value="create"/>
            <property name="javax.persistence.schema-generation.create-source" value="metadata"/>
            <property name="javax.persistence.schema-generation.drop-source" value="metadata"/>
        </properties>
    </persistence-unit>

The example is of course not working properly, as it does not use the XA data source

raphaelLacerda commented 4 years ago

i have the same problem, and when i changed to XADatasource i got the follow error when i try to sabe two instances

Caused by: javax.transaction.RollbackException: ARJUNA016083: Cannot register synchronization because the transaction is in aborted state
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.registerSynchronizationImple(TransactionImple.java:396)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.registerSynchronization(TransactionImple.java:377)
    at com.kumuluz.ee.jta.common.datasources.JtaXAConnectionWrapper.jtaPreInvoke(JtaXAConnectionWrapper.java:610)
    ... 103 more

trying to save

Hibernate:
    insert
    into
        ENDERECO
        (bairro, cep, cidade, estado, logradouro, numero)
    values
        (?, ?, ?, ?, ?, ?)
Hibernate:
    insert
    into
        FORNECEDOR
        (ativo, cnpj, cpf, dataEntrada, email, endereco_id, nome, telefoneCelular)
    values
        (?, ?, ?, ?, ?, ?, ?, ?)
2019-12-31 16:58:09 WARN  jta:? - ARJUNA016089: TransactionImple.enlistResource - xa_start  - caught: XAException.XAER_INVAL for < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffffc0a8006b:cd0d:5e0b9a40:3, node_name=1, branch_uid=0:ffffc0a8006b:cd0d:5e0b9a40:6, subordinatenodename=null, eis_name=0 >
com.mysql.jdbc.jdbc2.optional.MysqlXAException: XAER_INVAL: Invalid arguments (or unsupported command)
    at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.mapXAExceptionFromSQLException(MysqlXAConnection.java:581)
jmezna commented 4 years ago

@raphaelLacerda Which version of KumuluzEE are you using?

MBJuric commented 4 years ago

@salvadormarcos

Is it okay to submit the code this way? Or should I send as you suggested earlier?

Hello, I was wondering how far is your implementation of Agroal. The proposed way to submit the code is ok. Thanks in advance!

salvadormarcos commented 4 years ago

Hello @MBJuric. I finished the implementation before sending this question. Before submitting the code this question arose and I was waiting for the answer to any possible changes.

I will send the PR. Thanks

jmezna commented 4 years ago

Fixed in #158