-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 1 post ] 
Author Message
 Post subject: Multithreading transaction hanging during persisting entity
PostPosted: Wed Mar 11, 2015 2:16 pm 
Newbie

Joined: Wed Mar 11, 2015 2:14 pm
Posts: 1
I've got a bean definition with an entityManager like this:

Code:
@Stateless
    public class JPABean<T> {
   
        private static final Logger LOG = Logger.getLogger(JPABean.class);
   
        @PersistenceContext(unitName = "myPersistanceSettings")
        private EntityManager em;
   
        public void write(T o) {
            LOG.info("PERSISTING");
            em.persist(o);
            LOG.info("FLASHING");
            em.flush();
            LOG.info("SUCCESS");
        }

My persistance.xml

Code:
<persistence-unit name="eSystemJPA" transaction-type="JTA" >
       <provider>org.hibernate.ejb.HibernatePersistence</provider>
       <jta-data-source>java:jboss/datasources/myDS</jta-data-source>
       <properties>
          <property name="hibernate.show_sql" value="true" />
          <property name="hibernate.hbm2ddl.auto" value="validate" />
          <property name="hibernate.dialect" value="org.hibernate.dialect.PostgreSQLDialect"/>
          <property name="hibernate.transaction.jta.platform" value="org.hibernate.service.jta.platform.internal.JBossAppServerJtaPlatform" />
       </properties>
    </persistence-unit>


My api:

Code:
@Path("activityAPI")
    public class ActivityAPI {
   
       private static final Logger log = Logger.getLogger(ActivityAPI.class);
       
       @EJB
       private JPABean<ActivityLogEntry> activityJpa;
   
       @POST
       @Consumes(MediaType.APPLICATION_JSON)
       @Produces(MediaType.APPLICATION_JSON)
       public Response reportActivity(@Context HttpServletRequest hsr, final ActivityAPIRequest body) { ...


My standalone.xml with datasource:



Code:
<datasource jta="true" jndi-name="java:jboss/datasources/myDS" pool-name="PostgrePool" enabled="true" spy="true" use-ccm="false">
                <connection-url>jdbc:postgresql://localhost/postgres</connection-url>
                <driver>postgres</driver>
                <pool>
                    <min-pool-size>10</min-pool-size>
                    <max-pool-size>100</max-pool-size>
                    <prefill>true</prefill>
                </pool>
                <security>
                    <user-name>postgres</user-name>
                    <password>postgres</password>
                </security>
                <validation>
                    <validate-on-match>false</validate-on-match>
                    <background-validation>false</background-validation>
                </validation>
                <statement>
                    <share-prepared-statements>false</share-prepared-statements>
                </statement>
            </datasource>


And i'm receiving:

Code:
2015-03-11 17:48:39,945 INFO    [JPABean.write]: PERSISTING
    2015-03-11 17:48:39,946 INFO    [AbstractLoggingWriter.write]: INFO   [JPABean.write]: PERSISTING
    2015-03-11 17:48:39,946 DEBUG   [TransactionCoordinatorImpl.attemptToRegisterJtaSync]: Skipping JTA sync registration due to auto join checking
    2015-03-11 17:48:39,946 INFO    [AbstractLoggingWriter.write]: DEBUG  [TransactionCoordinatorImpl.attemptToRegisterJtaSync]: Skipping JTA sync registration due to auto join checking
    2015-03-11 17:48:39,947 DEBUG   [TransactionCoordinatorImpl.attemptToRegisterJtaSync]: successfully registered Synchronization
    2015-03-11 17:48:39,947 INFO    [AbstractLoggingWriter.write]: DEBUG  [TransactionCoordinatorImpl.attemptToRegisterJtaSync]: successfully registered Synchronization
    2015-03-11 17:48:39,947 DEBUG   [AbstractEntityManagerImpl.joinTransaction]: Looking for a JTA transaction to join
    2015-03-11 17:48:39,947 INFO    [AbstractLoggingWriter.write]: DEBUG  [AbstractEntityManagerImpl.joinTransaction]: Looking for a JTA transaction to join
    2015-03-11 17:48:39,948 INFO    [AbstractLoggingWriter.write]: Hibernate: select nextval ('hibernate_sequence')
    2015-03-11 17:48:39,949 DEBUG   [LogicalConnectionImpl.obtainConnection]: Obtaining JDBC connection
    2015-03-11 17:48:39,949 INFO    [AbstractLoggingWriter.write]: DEBUG  [LogicalConnectionImpl.obtainConnection]: Obtaining JDBC connection
    2015-03-11 17:48:39,950 DEBUG   [LogicalConnectionImpl.obtainConnection]: Obtained JDBC connection
    2015-03-11 17:48:39,950 INFO    [AbstractLoggingWriter.write]: DEBUG  [LogicalConnectionImpl.obtainConnection]: Obtained JDBC connection
    2015-03-11 17:48:39,952 DEBUG   [LogicalConnectionImpl.releaseConnection]: Releasing JDBC connection
    2015-03-11 17:48:39,952 INFO    [AbstractLoggingWriter.write]: DEBUG  [LogicalConnectionImpl.releaseConnection]: Releasing JDBC connection
    2015-03-11 17:48:39,953 DEBUG   [LogicalConnectionImpl.releaseConnection]: Released JDBC connection
    2015-03-11 17:48:39,953 INFO    [AbstractLoggingWriter.write]: DEBUG  [LogicalConnectionImpl.releaseConnection]: Released JDBC connection
    2015-03-11 17:48:39,954 INFO    [JPABean.write]: FLASHING
    2015-03-11 17:48:39,955 INFO    [AbstractLoggingWriter.write]: INFO   [JPABean.write]: FLASHING
    2015-03-11 17:48:39,957 INFO    [AbstractLoggingWriter.write]: DEBUG  [ActivityAPI.reportActivity]: POST Received PUT reportActivity
    2015-03-11 17:48:39,957 DEBUG   [EntityPrinter.toString]: Listing entities:
    2015-03-11 17:48:39,957 INFO    [AbstractLoggingWriter.write]: DEBUG  [EntityPrinter.toString]: Listing entities:
    2015-03-11 17:48:39,958 DEBUG   [EntityPrinter.toString]: ActivityLogEntry{... body ...}
    2015-03-11 17:48:39,958 INFO    [AbstractLoggingWriter.write]: DEBUG  [EntityPrinter.toString]: ActivityLogEntry{... body ...}
    2015-03-11 17:48:39,959 INFO    [JPABean.write]: PERSISTING
    2015-03-11 17:48:39,959 INFO    [AbstractLoggingWriter.write]: INFO   [JPABean.write]: PERSISTING
    2015-03-11 17:48:39,962 INFO    [AbstractLoggingWriter.write]: Hibernate: insert into activity_log_entry (all columns) values (?, ?, ?, ?, ?, ?, ?, ?, ?)

So in fact there is a problem with persisting (inserting) 2 entities into a table. I was trying to add @Transactional annotation on my public writing method and on my api, but it doesn't work. I'm using:

    postgressql - 9.3
    jboss-ejb-api_3.2_spec
    jboss-servlet-api_3.1_spec
    resteasy-jaxrs
    hibernate-entitymanager
    hibernate-validator
    driver postresql>9.3-1102-jdbc41
    wildfly 8.2 or wildfly 8.0

logs from hibernate:

Code:
2015-03-11 17:53:39,947 WARN    [SynchronizationCallbackCoordinatorTrackingImpl.afterCompletion]: HHH000451: Transaction afterCompletion called by a background thread; delaying afterCompletion processing until the original thread can handle it. [status=4]


Trace from wildfly

Code:
17:53:39,944 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000001:62455507:550071b3:35 in state  RUN
        17:53:39,945 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffff7f000001:62455507:550071b3:35 invoked while multiple threads active within it.
        17:53:39,946 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffff7f000001:62455507:550071b3:35 aborting with 1 threads active!
        17:53:39,957 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000001:62455507:550071b3:3b in state  RUN
        17:53:40,445 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000001:62455507:550071b3:35 in state  CANCEL
        17:53:40,446 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012378: ReaperElement appears to be wedged: org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:231)
        org.apache.log4j.JBossAppenderHandler.doPublish(JBossAppenderHandler.java:42)
        org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:79)
        org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:296)
        org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
        org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
        org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
        org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
        org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
        org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
        org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)
        org.jboss.logmanager.Logger.logRaw(Logger.java:721)
        org.jboss.logmanager.Logger.log(Logger.java:672)
        org.jboss.logging.JBossLogManagerLogger.doLogf(JBossLogManagerLogger.java:50)
        org.jboss.logging.Logger.logf(Logger.java:2096)
        org.hibernate.internal.CoreMessageLogger_$logger.rollbackFromBackgroundThread(CoreMessageLogger_$logger.java:1032)
        org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorTrackingImpl.afterCompletion(SynchronizationCallbackCoordinatorTrackingImpl.java:85)
        org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.afterCompletion(RegisteredSynchronization.java:56)
        com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96)
        com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:532)
        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)
       
        17:53:40,457 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000001:62455507:550071b3:3b in state  SCHEDULE_CANCEL
        17:53:40,947 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000001:62455507:550071b3:35 in state  CANCEL_INTERRUPTED
        17:53:40,948 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:ffff7f000001:62455507:550071b3:35 -- worker marked as zombie and TX scheduled for mark-as-rollback
        17:53:40,949 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012110: TransactionReaper::check successfuly marked TX 0:ffff7f000001:62455507:550071b3:35 as rollback only
        17:53:40,948 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 1) ARJUNA012095: Abort of action id 0:ffff7f000001:62455507:550071b3:3b invoked while multiple threads active within it.
        17:53:40,949 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 1) ARJUNA012108: CheckedAction::check - atomic action 0:ffff7f000001:62455507:550071b3:3b aborting with 1 threads active!
        17:53:40,949 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 1) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 1,5,main] successfully canceled TX 0:ffff7f000001:62455507:550071b3:3b


Every suggestion will be extremaly helpful for me :)


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 1 post ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.