CODEWITHSUNDEEP
javahibernatepostgresqlwildflyentitymanager
Konrad
Konrad

Reputation: 1635

Wildfly 8.0.0.Final + EntityManager + PostgreSQL - idle in transaction

I have the following code running on Wildfly 8.0.0.Final:

@Stateful
public class MyJPABean<T> {

    @PersistenceContext(unitName = "myUnitName")
    private EntityManager em;

    @TransactionAttribute(TransactionAttributeType.REQUIRED)
    public void write(T entity) {
        em.persist(entity);
        em.flush();
    }

    @TransactionAttribute(TransactionAttributeType.REQUIRED)
    public void update(T entity) {
        em.merge(entity);
    }
}

Both write and update methods are called parallely, because they are called directly from another class which handles HTTP requests:

@Path("api")
public class MyApiController {

    private MyJPABean<MyJpaModel> jpaBean;

    @POST
    @Consumes(MediaType.APPLICATION_JSON)
    @Produces(MediaType.APPLICATION_JSON)
    public void handlePost(MyJpaModel myJpaModel) {
       jpaBean.write(myJpaModel);
    }
}

Some of the the "write" method calls are successful, but from time to time, when the "write" method is called parallely by multiple threads, it starts to hang on em.persist(entity).

At PostgreSQL server side I can see transaction in state: "idle in transaction" with query: "select nextval ('hibernate_sequence')" or insert query that was created from the entity I just tried to persist.

When this problem happens I am not able to persist entities anymore. Everything hangs on em.persist(entity). Either I am not able to kill wildfly process, I have to kill it with -9 signal.

Is there anything I am doing wrong?

After some time (when the timeout occurs) I can see the following warnings in the application logs:

16:44:30,590 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000101:-231d9b5d:55030494:2d in state  RUN
16:44:30,591 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffff7f000101:-231d9b5d:55030494:2d invoked while multiple threads active within it.
16:44:30,591 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffff7f000101:-231d9b5d:55030494:2d aborting with 1 threads active!
16:44:30,598 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000101:-231d9b5d:55030494:35 in state  RUN
16:44:31,090 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000101:-231d9b5d:55030494:2d in state  CANCEL
16:44:31,092 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012378: ReaperElement appears to be wedged: com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:487)
com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:463)
com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:118)
com.arjuna.ats.arjuna.AtomicAction.cancel(AtomicAction.java:215)
com.arjuna.ats.arjuna.coordinator.TransactionReaper.doCancellations(TransactionReaper.java:377)
com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread.run(ReaperWorkerThread.java:78)

16:44:31,100 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000101:-231d9b5d:55030494:35 in state  SCHEDULE_CANCEL
16:44:31,594 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000101:-231d9b5d:55030494:2d in state  CANCEL_INTERRUPTED
16:44:31,595 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012120: TransactionReaper::check worker Thread[Transaction Reaper Worker 0,5,main] not responding to interrupt when cancelling TX 0:ffff7f000101:-231d9b5d:55030494:2d -- worker marked as zombie and TX scheduled for mark-as-rollback
16:44:31,596 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 1) ARJUNA012095: Abort of action id 0:ffff7f000101:-231d9b5d:55030494:35 invoked while multiple threads active within it.
16:44:31,597 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012110: TransactionReaper::check successfuly marked TX 0:ffff7f000101:-231d9b5d:55030494:2d as rollback only
16:44:31,597 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 1) ARJUNA012108: CheckedAction::check - atomic action 0:ffff7f000101:-231d9b5d:55030494:35 aborting with 1 threads active!
16:44:31,600 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000101:-231d9b5d:55030494:35 in state  CANCEL
16:44:31,602 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012378: ReaperElement appears to be wedged: org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:231)

As a jdbc driver, "postgresql-9.2-1004.jdbc41" is used. PostgreSQL server version is "9.3". I also had c3p0 on the classpath, but even when I delete this dependency, problem apeears.

Upvotes: 1

Views: 1150

Answers (1)

Aparna Chaudhary
Aparna Chaudhary

Reputation: 1335

I've prepared a sample application using JAX-RS, EJB and JPA - https://github.com/aparnachaudhary/prototypes/tree/master/jaxrs-db-access. I used the JMeter script to access the REST endpoint with multiple threads. But I could not reproduce the issue with PostgreSQL 9.3, postgresql-9.3-1103.jdbc41.jar and WildFly 8.1.0.Final.

Upvotes: 1

Related Questions