1 2 Previous Next 23 Replies Latest reply on Aug 29, 2016 2:00 PM by christopher.j.willems

    problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final

    christopher.j.willems

      hi ,

       

      we are running a project using eclipselink 2.5.2 on wildfly10 .

       

      during testing we have seen that wildfly  does not handle the lazy relationship between objects properly after a server restart .

       

      we have the following :

      - a many to many mapping between Person and PersonnelClass using a link table (classes attached )

       

        // bi-directional many-to-one association to PersonnelClass from Person entity

          @OneToMany(mappedBy = "person", cascade = {CascadeType.ALL},  fetch = FetchType.LAZY)

          private List<LinkPersonnelClassPersonDefinedBy> personnelClasses = new ArrayList<LinkPersonnelClassPersonDefinedBy>();

       

       

       

        // bi-directional many-to-one association to Person from PersonnelClass entity

        @OneToMany(mappedBy = "personnelClass", cascade = {CascadeType.ALL},  fetch = FetchType.LAZY)

         private List<LinkPersonnelClassPersonDefinedBy> persons = new ArrayList<LinkPersonnelClassPersonDefinedBy>();

       

       

       

      in LinkPersonnelClassPersonDefinedBy entity

          // bi-directional many-to-one association to PersonnelClass

          @ManyToOne(cascade = {CascadeType.REFRESH}, fetch = FetchType.EAGER)

          // (cascade = { CascadeType.REFRESH })

          @JoinColumn(name = "PECL_UIID")

          private PersonnelClass personnelClass;

       

       

          // bi-directional many-to-one association to Personnel

          @ManyToOne(cascade = {CascadeType.REFRESH}, fetch = FetchType.EAGER)

          @JoinColumn(name = "PERS_UIID")

          private Person person;

       

       

       

      we then use a transaction to add relationship between objects if they don't exist , to check we use the getters in the entities . Everything works fine until we restart the server ... after the restart the existing relationship is found on the first execution of the transaction BUT THE SECOND TIME IT IS GONE ...i read about some issues with eclipse link on older versions but not 10.x

       

      any ideas as this seems a major bug to me , on glassfish and SAP NETWEAVER we have the same coding without having troubles

       

       

       

      @Stateless

      @TransactionManagement(TransactionManagementType.BEAN)

      public class PersonXMLServiceCore implements PersonXMLServiceCoreLocal {

       

       

        @PersistenceContext(unitName = "VERI95")

        EntityManager em;

       

       

        @Resource

        UserTransaction transaction;

       

        transaction.begin();

      ...

      Collection<PersonnelClass> personnelClasses = displayPersonnelClassDefinedBy(pe);

        if (personnelClasses == null) {

        existingDefinedBy.addAll(personnelClasses);....

        }

       

      ....

        transaction.commit();

        • 1. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
          smarlow

          I wonder if EclipseLink Weaving is working during application deployment, which I believe is required for EclipseLink lazy relationship support.  With dynamic weaving, application classes are updated during application deployment, as they are loaded by the application server.  Do you know which type of EclipseLink weaving (static or dynamic)?  Static weaving is done when you compile your application and dynamic weaving is done later during application deployment.

           

          In order for this to work, EclipseLink calls PersistenceUnitInfo.html#addTransformer to register their Java Class transformer with the WildFly JPA deployer.  It may be that the transformer is registered too late, after your entity classes are already loaded.

           

          Can you show us your persistence.xml contents?

          • 2. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
            christopher.j.willems

            hi,

             

            i use dynamic weaving , switching to static had no effect ... this problem is puzzling , right after server start everything is working , until I commit the transaction. After the transaction commit you cannot even use .size() to trigger the relationship ...

             

            <?xml version="1.0" encoding="UTF-8"?>

            <persistence version="2.0"

              xmlns="http://java.sun.com/xml/ns/persistence" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"

              xsi:schemaLocation="http://java.sun.com/xml/ns/persistence http://java.sun.com/xml/ns/persistence/persistence_2_0.xsd">

              <persistence-unit name="VERI95" transaction-type="JTA">

              <provider>org.eclipse.persistence.jpa.PersistenceProvider</provider>

              <jta-data-source>java:/veri95</jta-data-source>

               <!--  <exclude-unlisted-classes>false</exclude-unlisted-classes> -->

              <class>inxites.be.veri95.ejb.entity.common.AuthorizationRoles</class>

            ....

              <properties><property name="eclipselink.target-server" value="JBoss"/>

              <property name="eclipselink.deploy-on-startup" value="true"/>

              <property name="eclipselink.ddl-generation" value="create-tables"/>

              </properties>

              </persistence-unit>

            </persistence>

            • 3. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
              smarlow

              Perhaps its not a weaving issue then (since static had no effect).  Try enabling TRACE logging for the JPA container + JTA transaction manager, so you get more insight as to what is going on.  See https://docs.jboss.org/author/display/WFLY10/JPA+Reference+Guide#JPAReferenceGuide-Troubleshooting and set "com.arjuna" to TRACE and "org.jboss.as.jpa" to TRACE level as well.  Enabling EclipseLink trace output may also help. 

              1 of 1 people found this helpful
              • 4. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                christopher.j.willems

                hi,

                 

                below is the trace from right after server restart , 2 updates after each other ...

                 

                 

                 

                 

                 

                2016-08-23 21:35:42,498 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) getting persistence provider list (null) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear.veri95web.war:main" from Service Module Loader)

                2016-08-23 21:35:42,498 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) saving new persistence provider list ([]) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear.veri95web.war:main" from Service Module Loader)

                2016-08-23 21:35:42,498 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) added new persistence provider (org.eclipse.persistence.jpa.PersistenceProvider) to provider list ([class org.eclipse.persistence.jpa.PersistenceProvider])

                2016-08-23 21:35:42,498 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) getting persistence provider list (null) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear.veri95ejb.jar:main" from Service Module Loader)

                2016-08-23 21:35:42,498 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) saving new persistence provider list ([]) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear.veri95ejb.jar:main" from Service Module Loader)

                2016-08-23 21:35:42,499 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) added new persistence provider (org.eclipse.persistence.jpa.PersistenceProvider) to provider list ([class org.eclipse.persistence.jpa.PersistenceProvider])

                2016-08-23 21:35:42,499 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) getting persistence provider list (null) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear:main" from Service Module Loader)

                2016-08-23 21:35:42,499 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) saving new persistence provider list ([]) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear:main" from Service Module Loader)

                2016-08-23 21:35:42,499 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) added new persistence provider (org.eclipse.persistence.jpa.PersistenceProvider) to provider list ([class org.eclipse.persistence.jpa.PersistenceProvider])

                2016-08-23 21:35:42,499 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) install persistence unit definitions for ear veri95app.ear

                2016-08-23 21:35:42,499 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) install persistence unit definitions for ear veri95jpa.jar

                2016-08-23 21:35:42,499 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) adding 'vfs:/C:/wildfly/wildfly-10.0.0.Final/standalone/deployments/veri95app.ear/lib/veri95jpa.jar/' to annotation index map

                2016-08-23 21:35:42,499 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) adding 'vfs:/C:/wildfly/wildfly-10.0.0.Final/standalone/deployments/veri95app.ear/veri95ejb.jar/' to annotation index map

                2016-08-23 21:35:42,499 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) deployment veri95app.ear is using org.eclipse.persistence.jpa.PersistenceProvider

                2016-08-23 21:35:42,499 INFO  [org.jboss.weld.deployer] (MSC service thread 1-8) WFLYWELD0006: Starting Services for CDI deployment: veri95app.ear

                2016-08-23 21:35:42,526 INFO  [org.jboss.weld.Version] (MSC service thread 1-8) WELD-000900: 2.3.2 (Final)

                2016-08-23 21:35:42,533 INFO  [org.jboss.weld.deployer] (MSC service thread 1-1) WFLYWELD0009: Starting weld service for deployment veri95app.ear

                2016-08-23 21:35:43,462 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) getting persistence provider list ([class org.eclipse.persistence.jpa.PersistenceProvider]) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear.veri95web.war:main" from Service Module Loader)

                2016-08-23 21:35:43,462 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) added new persistence provider (org.eclipse.persistence.jpa.PersistenceProvider) to provider list ([class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider])

                2016-08-23 21:35:43,462 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) getting persistence provider list ([class org.eclipse.persistence.jpa.PersistenceProvider]) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear.veri95ejb.jar:main" from Service Module Loader)

                2016-08-23 21:35:43,463 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) added new persistence provider (org.eclipse.persistence.jpa.PersistenceProvider) to provider list ([class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider])

                2016-08-23 21:35:43,463 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) getting persistence provider list ([class org.eclipse.persistence.jpa.PersistenceProvider]) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear:main" from Service Module Loader)

                2016-08-23 21:35:43,463 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) added new persistence provider (org.eclipse.persistence.jpa.PersistenceProvider) to provider list ([class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider])

                2016-08-23 21:35:43,463 TRACE [org.jboss.as.jpa] (MSC service thread 1-8) install persistence unit definitions for war null

                2016-08-23 21:35:43,476 INFO  [org.infinispan.configuration.cache.EvictionConfigurationBuilder] (ServerService Thread Pool -- 58) ISPN000152: Passivation configured without an eviction policy being selected. Only manually evicted entities will be passivated.

                2016-08-23 21:35:43,477 INFO  [org.infinispan.configuration.cache.EvictionConfigurationBuilder] (ServerService Thread Pool -- 58) ISPN000152: Passivation configured without an eviction policy being selected. Only manually evicted entities will be passivated.

                2016-08-23 21:35:43,477 INFO  [org.infinispan.configuration.cache.EvictionConfigurationBuilder] (ServerService Thread Pool -- 58) ISPN000152: Passivation configured without an eviction policy being selected. Only manually evicted entities will be passivated.

                2016-08-23 21:35:43,478 INFO  [org.infinispan.configuration.cache.EvictionConfigurationBuilder] (ServerService Thread Pool -- 58) ISPN000152: Passivation configured without an eviction policy being selected. Only manually evicted entities will be passivated.

                2016-08-23 21:35:44,073 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 58) WFLYCLINF0002: Started client-mappings cache from ejb container

                2016-08-23 21:35:44,519 TRACE [org.jboss.as.jpa] (MSC service thread 1-2) getting persistence provider list ([class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider]) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear.veri95web.war:main" from Service Module Loader)

                2016-08-23 21:35:44,519 TRACE [org.jboss.as.jpa] (MSC service thread 1-2) added new persistence provider (org.eclipse.persistence.jpa.PersistenceProvider) to provider list ([class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider])

                2016-08-23 21:35:44,519 TRACE [org.jboss.as.jpa] (MSC service thread 1-2) getting persistence provider list ([class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider]) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear.veri95ejb.jar:main" from Service Module Loader)

                2016-08-23 21:35:44,519 TRACE [org.jboss.as.jpa] (MSC service thread 1-2) added new persistence provider (org.eclipse.persistence.jpa.PersistenceProvider) to provider list ([class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider])

                2016-08-23 21:35:44,519 TRACE [org.jboss.as.jpa] (MSC service thread 1-2) getting persistence provider list ([class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider]) for deployment (ModuleClassLoader for Module "deployment.veri95app.ear:main" from Service Module Loader)

                2016-08-23 21:35:44,519 TRACE [org.jboss.as.jpa] (MSC service thread 1-2) added new persistence provider (org.eclipse.persistence.jpa.PersistenceProvider) to provider list ([class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider, class org.eclipse.persistence.jpa.PersistenceProvider])

                2016-08-23 21:35:46,094 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery second pass at Tue, 23 Aug 2016 21:35:46

                2016-08-23 21:35:46,095 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()

                2016-08-23 21:35:46,095 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, InputObjectState Uid   : 0:0:0:0:0

                InputObjectState Type  : null

                InputObjectState Size  : 0

                InputObjectState Buffer: , -1)

                2016-08-23 21:35:46,095 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()

                2016-08-23 21:35:46,095 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/BasicAction/TwoPhaseCoordinator/AtomicActionConnectable, InputObjectState Uid   : 0:0:0:0:0

                InputObjectState Type  : null

                InputObjectState Size  : 40

                InputObjectState Buffer: , -1)

                2016-08-23 21:35:46,095 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) 

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule second pass

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) 

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - second pass

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) 

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) XARecoveryModule state change BETWEEN_PASSES->SECOND_PASS

                 

                 

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - second pass

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.transactionInitiatedRecovery completed

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.resourceInitiatedRecovery completed

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) XARecoveryModule state change SECOND_PASS->IDLE

                 

                 

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) 

                2016-08-23 21:35:46,096 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE

                2016-08-23 21:35:46,097 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread backing off

                2016-08-23 21:35:46,538 WARN  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002155: Provider class inxites.be.veri95.ejb.service.util.jersey.providers.exception.GenericExceptionMapper is already registered.  2nd registration is being ignored.

                2016-08-23 21:35:47,342 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool -- 64) WFLYUT0021: Registered web context: /veri95web

                2016-08-23 21:35:47,361 INFO  [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0010: Deployed "mongo-java-driver-3.0.4.jar" (runtime-name : "mongo-java-driver-3.0.4.jar")

                2016-08-23 21:35:47,361 INFO  [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0010: Deployed "commons-lang3-3.4.jar" (runtime-name : "commons-lang3-3.4.jar")

                2016-08-23 21:35:47,361 INFO  [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0010: Deployed "sqljdbc4.jar" (runtime-name : "sqljdbc4.jar")

                2016-08-23 21:35:47,361 INFO  [org.jboss.as.server] (ServerService Thread Pool -- 34) WFLYSRV0010: Deployed "veri95app.ear" (runtime-name : "veri95app.ear")

                2016-08-23 21:35:47,361 INFO  [org.jboss.as.server] (ServerService Thread Pool -- 34) WFLYSRV0010: Deployed "Mongo" (runtime-name : "Mongo")

                2016-08-23 21:35:47,472 INFO  [org.jboss.as] (Controller Boot Thread) WFLYSRV0060: Http management interface listening on http://127.0.0.1:9990/management

                2016-08-23 21:35:47,472 INFO  [org.jboss.as] (Controller Boot Thread) WFLYSRV0051: Admin console listening on http://127.0.0.1:9990

                2016-08-23 21:35:47,472 INFO  [org.jboss.as] (Controller Boot Thread) WFLYSRV0025: WildFly Full 10.0.0.Final (WildFly Core 2.0.10.Final) started in 13218ms - Started 4847 of 5151 services (431 services are lazy, passive or on-demand)

                2016-08-23 21:36:33,554 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-2) RESTEASY002225: Deploying javax.ws.rs.core.Application: class inxites.be.veri95.ejb.service.util.jersey.application.V2Application

                2016-08-23 21:36:33,555 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-2) RESTEASY002215: Adding singleton provider org.jboss.resteasy.plugins.interceptors.CorsFilter from Application class inxites.be.veri95.ejb.service.util.jersey.application.V2Application

                2016-08-23 21:36:33,856 INFO  [stdout] (default task-2)

                2016-08-23 21:36:33,856 INFO  [stdout] (default task-2) EVENT

                2016-08-23 21:36:33,856 INFO  [stdout] (default task-2)  SEVERITY: 2

                2016-08-23 21:36:33,856 INFO  [stdout] (default task-2)  MESSAGE: cvc-complex-type.2.1: Element '' must have no character or element information item [children], because the type's content type is empty.

                2016-08-23 21:36:33,856 INFO  [stdout] (default task-2)  LINKED EXCEPTION: null

                2016-08-23 21:36:33,856 INFO  [stdout] (default task-2)  LOCATOR

                2016-08-23 21:36:33,856 INFO  [stdout] (default task-2)  LINE NUMBER: -1

                2016-08-23 21:36:33,856 INFO  [stdout] (default task-2)  COLUMN NUMBER: -1

                2016-08-23 21:36:33,857 INFO  [stdout] (default task-2)  OFFSET: -1

                2016-08-23 21:36:33,857 INFO  [stdout] (default task-2)  OBJECT: null

                2016-08-23 21:36:33,857 INFO  [stdout] (default task-2)  NODE: null

                2016-08-23 21:36:33,857 INFO  [stdout] (default task-2)  URL: null

                 

                 

                2016-08-23 21:36:33,902 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.begin

                2016-08-23 21:36:33,903 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:33,903 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::BasicAction()

                2016-08-23 21:36:33,903 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:e

                2016-08-23 21:36:33,903 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:e

                2016-08-23 21:36:33,903 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:33,904 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:e, 1)

                2016-08-23 21:36:33,904 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e adding Thread[default task-2,5,main]

                2016-08-23 21:36:33,905 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:33,905 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:e status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:33,905 TRACE [com.arjuna.ats.arjuna] (default task-2) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:e status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:33,905 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run ()

                2016-08-23 21:36:33,906 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check ()

                2016-08-23 21:36:33,906 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check - comparing 1471981593905

                2016-08-23 21:36:33,906 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,main] sleeping for 599999

                2016-08-23 21:36:33,929 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.suspend

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e removing TSThread:1

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e removing TSThread:1 result = true

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.begin

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::BasicAction()

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:f

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:f

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:f, 1)

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:f adding Thread[default task-2,5,main]

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:f adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:f status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:33,930 TRACE [com.arjuna.ats.arjuna] (default task-2) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:f status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:33,934 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,934 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.commit

                2016-08-23 21:36:33,934 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:33,934 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:f

                2016-08-23 21:36:33,934 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:f) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:33,934 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:f removing TSThread:1

                2016-08-23 21:36:33,935 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:f removing TSThread:1 result = true

                2016-08-23 21:36:33,935 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:f status: ActionStatus.COMMITTED )

                2016-08-23 21:36:33,935 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.resume

                2016-08-23 21:36:33,935 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e adding Thread[default task-2,5,main]

                2016-08-23 21:36:33,935 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:33,942 DEBUG [org.jboss.as.jpa] (default task-2) created new TransactionScopedEntityManager for unit name=veri95app.ear#VERI95

                2016-08-23 21:36:33,942 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,942 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.suspend

                2016-08-23 21:36:33,942 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e removing TSThread:1

                2016-08-23 21:36:33,942 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e removing TSThread:1 result = true

                2016-08-23 21:36:33,942 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.begin

                2016-08-23 21:36:33,942 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:33,942 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::BasicAction()

                2016-08-23 21:36:33,942 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:10

                2016-08-23 21:36:33,942 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:10

                2016-08-23 21:36:33,942 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:10, 1)

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:10 adding Thread[default task-2,5,main]

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:10 adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:10 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:10 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.suspend

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:10 removing TSThread:1

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:10 removing TSThread:1 result = true

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.begin

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::BasicAction()

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:11

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:11

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:11, 1)

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:11 adding Thread[default task-2,5,main]

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:11 adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:11 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.arjuna] (default task-2) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:11 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:33,943 DEBUG [org.jboss.as.jpa] (default task-2) created new TransactionScopedEntityManager for unit name=veri95app.ear#VERI95

                2016-08-23 21:36:33,943 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,944 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.commit

                2016-08-23 21:36:33,944 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:33,944 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:11

                2016-08-23 21:36:33,944 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:11) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:33,944 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:11 removing TSThread:1

                2016-08-23 21:36:33,944 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:11 removing TSThread:1 result = true

                2016-08-23 21:36:33,944 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:11 status: ActionStatus.COMMITTED )

                2016-08-23 21:36:33,944 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.resume

                2016-08-23 21:36:33,944 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:10 adding Thread[default task-2,5,main]

                2016-08-23 21:36:33,944 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:10 adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:33,946 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,946 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,946 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,955 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.registerSynchronization - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 420999812 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@1917f284

                2016-08-23 21:36:33,957 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: created entity manager session TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:10 status: ActionStatus.RUNNING >

                2016-08-23 21:36:33,958 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.registerInterposedSynchronization - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 410119716 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@1871ee24

                2016-08-23 21:36:33,958 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,959 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,959 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.equals

                2016-08-23 21:36:33,959 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:33,959 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,966 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,966 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'GeneralCustomizing.getCustomizingValueByGeneralCustomizingId' took 22ms

                2016-08-23 21:36:33,974 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,974 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.registerSynchronization - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1755441964 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@68a1eb2c

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,976 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,977 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:33,977 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,977 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,977 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,977 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,977 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:33,977 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,977 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,978 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,979 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.enlistResource ( LocalXAResourceImpl@578bf676[connectionListener=4ea62691 connectionManager=a1ecf04 warned=false currentXid=null productName=Microsoft SQL Server productVersion=11.00.3513 jndiName=java:/veri95] )

                2016-08-23 21:36:33,979 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,979 TRACE [com.arjuna.ats.arjuna] (default task-2) InputObjectState::InputObjectState()

                2016-08-23 21:36:33,979 TRACE [com.arjuna.ats.arjuna] (default task-2) FileSystemStore.allObjUids(EISNAME, InputObjectState Uid   : 0:0:0:0:0

                InputObjectState Type  : null

                InputObjectState Size  : 0

                InputObjectState Buffer: , -1)

                2016-08-23 21:36:33,979 TRACE [com.arjuna.ats.arjuna] (default task-2) OutputObjectState::OutputObjectState()

                2016-08-23 21:36:33,980 TRACE [com.arjuna.ats.arjuna] (default task-2) FileSystemStore.read_committed(0:ffffc0a80165:12b43ed:57965544:c0, EISNAME)

                2016-08-23 21:36:33,980 TRACE [com.arjuna.ats.arjuna] (default task-2) ShadowingStore.read_state(0:ffffc0a80165:12b43ed:57965544:c0, EISNAME, StateType.OS_ORIGINAL)

                2016-08-23 21:36:33,980 TRACE [com.arjuna.ats.arjuna] (default task-2) ShadowingStore.genPathName(0:ffffc0a80165:12b43ed:57965544:c0, EISNAME, StateType.OS_SHADOW)

                2016-08-23 21:36:33,980 TRACE [com.arjuna.ats.arjuna] (default task-2) FileSystemStore.genPathName(0:ffffc0a80165:12b43ed:57965544:c0, EISNAME, 10)

                2016-08-23 21:36:33,980 TRACE [com.arjuna.ats.arjuna] (default task-2) ShadowingStore.genPathName(0:ffffc0a80165:12b43ed:57965544:c0, EISNAME, StateType.OS_ORIGINAL)

                2016-08-23 21:36:33,980 TRACE [com.arjuna.ats.arjuna] (default task-2) FileSystemStore.genPathName(0:ffffc0a80165:12b43ed:57965544:c0, EISNAME, 11)

                2016-08-23 21:36:33,980 TRACE [com.arjuna.ats.arjuna] (default task-2) ShadowingStore.currentState(0:ffffc0a80165:12b43ed:57965544:c0, EISNAME) - returning StateStatus.OS_COMMITTED

                2016-08-23 21:36:33,980 TRACE [com.arjuna.ats.arjuna] (default task-2) ShadowingStore.genPathName(0:ffffc0a80165:12b43ed:57965544:c0, EISNAME, StateType.OS_ORIGINAL)

                2016-08-23 21:36:33,980 TRACE [com.arjuna.ats.arjuna] (default task-2) FileSystemStore.genPathName(0:ffffc0a80165:12b43ed:57965544:c0, EISNAME, 11)

                2016-08-23 21:36:33,980 TRACE [com.arjuna.ats.arjuna] (default task-2) FileSystemStore.openAndLock(C:\wildfly\wildfly-10.0.0.Final\standalone\data\tx-object-store\ShadowNoFileLockStore\defaultStore\EISNAME\0_ffffc0a80165_12b43ed_57965544_c0, FileLock.F_RDLCK, false)

                2016-08-23 21:36:33,981 TRACE [com.arjuna.ats.arjuna] (default task-2) InputObjectState::InputObjectState(0:ffffc0a80165:12b43ed:57965544:c0, EISNAME)

                2016-08-23 21:36:33,981 TRACE [com.arjuna.ats.arjuna] (default task-2) FileSystemStore.closeAndUnlock(C:\wildfly\wildfly-10.0.0.Final\standalone\data\tx-object-store\ShadowNoFileLockStore\defaultStore\EISNAME\0_ffffc0a80165_12b43ed_57965544_c0, java.io.FileInputStream@2ee2b121, null)

                2016-08-23 21:36:33,984 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 0:0:0:0:1 )

                2016-08-23 21:36:33,984 TRACE [com.arjuna.ats.arjuna] (default task-2) AbstractRecord::AbstractRecord (0:0:0:0:1)

                2016-08-23 21:36:33,984 TRACE [com.arjuna.ats.arjuna] (default task-2) LastResourceRecord()

                2016-08-23 21:36:33,985 TRACE [com.arjuna.ats.arjuna] (default task-2) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/LastResourceRecord for 0:0:0:0:1

                2016-08-23 21:36:33,986 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,989 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,991 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,991 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.commit

                2016-08-23 21:36:33,991 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:33,991 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.beforeCompletion - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 420999812 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@1917f284

                2016-08-23 21:36:33,991 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.beforeCompletion - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1755441964 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@68a1eb2c

                2016-08-23 21:36:33,991 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.beforeCompletion - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 410119716 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@1871ee24

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.delistResource ( LocalXAResourceImpl@578bf676[connectionListener=4ea62691 connectionManager=a1ecf04 warned=false currentXid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffffc0a80165:3d9ea16:57bca588:10, node_name=1, branch_uid=0:ffffc0a80165:3d9ea16:57bca588:16, subordinatenodename=null, eis_name=java:/veri95 > productName=Microsoft SQL Server productVersion=11.00.3513 jndiName=java:/veri95], 67108864 )

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:10

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::onePhaseCommit() for action-id 0:ffffc0a80165:3d9ea16:57bca588:10

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.arjuna] (default task-2) LastResourceRecord::topLevelPrepare() for 0:0:0:0:1

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.arjuna] (default task-2) LastResourceRecord::topLevelCommit() for 0:0:0:0:1

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:10) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:33,992 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.afterCompletion - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 410119716 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@1871ee24

                2016-08-23 21:36:33,992 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: closing entity managersession

                2016-08-23 21:36:33,993 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.afterCompletion - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1755441964 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@68a1eb2c

                2016-08-23 21:36:33,993 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.afterCompletion - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 420999812 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@1917f284

                2016-08-23 21:36:33,993 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:10 removing TSThread:1

                2016-08-23 21:36:33,993 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:10 removing TSThread:1 result = true

                2016-08-23 21:36:33,993 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:10 status: ActionStatus.COMMITTED )

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.begin

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::BasicAction()

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:17

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:17

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:17, 1)

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 adding Thread[default task-2,5,main]

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:33,995 TRACE [com.arjuna.ats.arjuna] (default task-2) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:33,996 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,996 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,996 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,996 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.registerSynchronization - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 569373618 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@21eff3b2

                2016-08-23 21:36:33,996 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: created entity manager session TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:33,996 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.registerInterposedSynchronization - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 995219079 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@3b51d687

                2016-08-23 21:36:33,996 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,996 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,996 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.equals

                2016-08-23 21:36:33,996 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:33,996 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateCreate' took 1ms

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.registerSynchronization - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1665555961 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@63465df9

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.enlistResource ( LocalXAResourceImpl@578bf676[connectionListener=4ea62691 connectionManager=a1ecf04 warned=false currentXid=null productName=Microsoft SQL Server productVersion=11.00.3513 jndiName=java:/veri95] )

                2016-08-23 21:36:33,997 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,998 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 0:0:0:0:1 )

                2016-08-23 21:36:33,998 TRACE [com.arjuna.ats.arjuna] (default task-2) AbstractRecord::AbstractRecord (0:0:0:0:1)

                2016-08-23 21:36:33,998 TRACE [com.arjuna.ats.arjuna] (default task-2) LastResourceRecord()

                2016-08-23 21:36:33,998 TRACE [com.arjuna.ats.arjuna] (default task-2) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/LastResourceRecord for 0:0:0:0:1

                2016-08-23 21:36:33,998 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:33,998 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,002 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,002 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,002 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,002 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,003 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,003 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateReplace' took 1ms

                2016-08-23 21:36:34,004 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,004 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,004 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,004 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,004 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,004 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,004 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,004 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,004 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.suspend

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 removing TSThread:1

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 removing TSThread:1 result = true

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.begin

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::BasicAction()

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1c

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1c

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:34,012 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:1c, 1)

                2016-08-23 21:36:34,013 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1c adding Thread[default task-2,5,main]

                2016-08-23 21:36:34,013 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1c adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:34,013 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1c status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:34,013 TRACE [com.arjuna.ats.arjuna] (default task-2) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1c status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:34,014 DEBUG [org.jboss.as.jpa] (default task-2) created new TransactionScopedEntityManager for unit name=veri95app.ear#VERI95

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.commit

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1c

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:1c) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1c removing TSThread:1

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1c removing TSThread:1 result = true

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1c status: ActionStatus.COMMITTED )

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.resume

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 adding Thread[default task-2,5,main]

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.suspend

                2016-08-23 21:36:34,014 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 removing TSThread:1

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 removing TSThread:1 result = true

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.begin

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::BasicAction()

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1d

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1d

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:1d, 1)

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1d adding Thread[default task-2,5,main]

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1d adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1d status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1d status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:34,015 DEBUG [org.jboss.as.jpa] (default task-2) created new TransactionScopedEntityManager for unit name=veri95app.ear#VERI95

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.commit

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1d

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:1d) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1d removing TSThread:1

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1d removing TSThread:1 result = true

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1d status: ActionStatus.COMMITTED )

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.resume

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 adding Thread[default task-2,5,main]

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,015 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,015 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,016 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,016 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'DatabaseQueue.countByObjectNameByObjectID' took 1ms

                2016-08-23 21:36:34,017 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,017 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,017 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,017 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,017 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,017 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,017 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,017 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,017 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,019 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,019 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,019 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,019 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,023 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,023 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'Person.getPersonByPersonID' took 4ms

                2016-08-23 21:36:34,023 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,023 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,023 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,023 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,023 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,023 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,023 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,023 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,023 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,027 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,027 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,027 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,027 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,027 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,027 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateCreate' took 0ms

                2016-08-23 21:36:34,028 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,028 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,028 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,028 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,028 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,028 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,028 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,028 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,028 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,029 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,030 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,030 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateReplace' took 1ms

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,030 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,032 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,032 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,032 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,032 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,032 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,032 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,032 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,032 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,032 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,038 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,038 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,039 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,039 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateCreate' took 1ms

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,039 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,041 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,041 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateReplace' took 0ms

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,041 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,043 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,043 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,043 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,043 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,043 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,043 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'DatabaseQueue.countByObjectNameByObjectID' took 0ms

                2016-08-23 21:36:34,044 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,044 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,044 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,044 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,044 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,044 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,044 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,044 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,044 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,046 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,046 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'Person.getPersonByPersonID' took 0ms

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,046 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,047 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,048 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,048 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,048 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,048 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,048 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,048 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'DatabaseQueue.countByObjectNameByObjectID' took 0ms

                2016-08-23 21:36:34,048 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,048 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,048 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,048 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,049 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,049 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,049 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,049 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,049 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,049 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,049 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,049 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,049 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,050 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,050 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'Person.getPersonByPersonID' took 1ms

                2016-08-23 21:36:34,050 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,050 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,050 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,050 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,050 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,050 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,050 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,050 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,050 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.suspend

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 removing TSThread:1

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 removing TSThread:1 result = true

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.begin

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::BasicAction()

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1e

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1e

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:1e, 1)

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1e adding Thread[default task-2,5,main]

                2016-08-23 21:36:34,051 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1e adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:34,052 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1e status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:34,052 TRACE [com.arjuna.ats.arjuna] (default task-2) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1e status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:34,052 DEBUG [org.jboss.as.jpa] (default task-2) created new TransactionScopedEntityManager for unit name=veri95app.ear#VERI95

                2016-08-23 21:36:34,052 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.commit

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1e

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:1e) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1e removing TSThread:1

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1e removing TSThread:1 result = true

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1e status: ActionStatus.COMMITTED )

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.resume

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 adding Thread[default task-2,5,main]

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,053 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,053 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,053 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'HierarchyScope.getHierarchyScopeByPath' took 0ms

                2016-08-23 21:36:34,054 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,054 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,054 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,054 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,054 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,054 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,054 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,054 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,054 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,057 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,057 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,057 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,057 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,057 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,060 TRACE [org.jboss.as.jpa] (default task-2) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.person.Person' took 3ms

                2016-08-23 21:36:34,060 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,060 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,060 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,060 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,061 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,061 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'GeneralCustomizing.getGeneralCustomizingByGeneralCustomizingIdByCustomizingValue' took 1ms

                2016-08-23 21:36:34,062 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,063 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,064 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,064 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:34,064 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,064 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,064 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,064 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,064 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,064 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,069 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,069 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,070 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,070 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,072 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,072 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.suspend

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 removing TSThread:1

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 removing TSThread:1 result = true

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.begin

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::BasicAction()

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1f

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1f

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:1f, 1)

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1f adding Thread[default task-2,5,main]

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1f adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1f status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:34,075 TRACE [com.arjuna.ats.arjuna] (default task-2) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1f status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:34,075 DEBUG [org.jboss.as.jpa] (default task-2) created new TransactionScopedEntityManager for unit name=veri95app.ear#VERI95

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.commit

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:1f

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:1f) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1f removing TSThread:1

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:1f removing TSThread:1 result = true

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:1f status: ActionStatus.COMMITTED )

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.resume

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 adding Thread[default task-2,5,main]

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,076 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,076 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,076 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'DatabaseQueue.countByObjectNameByObjectID' took 0ms

                2016-08-23 21:36:34,077 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,077 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,077 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,077 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,077 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,077 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,079 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,079 TRACE [org.jboss.as.jpa] (default task-2) createNamedQuery name 'PersonnelClass.getPersonnelClassByPersonnelClassID' took 2ms

                2016-08-23 21:36:34,079 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,079 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,080 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,080 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,080 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,080 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,080 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,081 TRACE [org.jboss.as.jpa] (default task-2) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.person.Person' took 1ms

                2016-08-23 21:36:34,082 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,082 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,082 TRACE [com.arjuna.ats.jta] (default task-2) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:34,082 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,082 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.RUNNING >

                2016-08-23 21:36:34,082 TRACE [org.jboss.as.jpa] (default task-2) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.person.PersonProperty' took 0ms

                2016-08-23 21:36:34,083 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,083 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,084 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,084 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,085 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.commit

                2016-08-23 21:36:34,085 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:34,085 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.beforeCompletion - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 569373618 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@21eff3b2

                2016-08-23 21:36:34,085 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.beforeCompletion - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1665555961 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@63465df9

                2016-08-23 21:36:34,085 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,086 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,086 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,086 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,086 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,088 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.beforeCompletion - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 995219079 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@3b51d687

                2016-08-23 21:36:34,088 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,088 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,088 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.delistResource ( LocalXAResourceImpl@578bf676[connectionListener=4ea62691 connectionManager=a1ecf04 warned=false currentXid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffffc0a80165:3d9ea16:57bca588:17, node_name=1, branch_uid=0:ffffc0a80165:3d9ea16:57bca588:1b, subordinatenodename=null, eis_name=java:/veri95 > productName=Microsoft SQL Server productVersion=11.00.3513 jndiName=java:/veri95], 67108864 )

                2016-08-23 21:36:34,088 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,088 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:17

                2016-08-23 21:36:34,088 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::onePhaseCommit() for action-id 0:ffffc0a80165:3d9ea16:57bca588:17

                2016-08-23 21:36:34,088 TRACE [com.arjuna.ats.arjuna] (default task-2) LastResourceRecord::topLevelPrepare() for 0:0:0:0:1

                2016-08-23 21:36:34,089 TRACE [com.arjuna.ats.arjuna] (default task-2) LastResourceRecord::topLevelCommit() for 0:0:0:0:1

                2016-08-23 21:36:34,089 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:17) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:34,089 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.afterCompletion - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 995219079 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@3b51d687

                2016-08-23 21:36:34,089 DEBUG [org.jboss.as.jpa] (default task-2) default task-2:transaction scoped EntityManager [veri95app.ear#VERI95]: closing entity managersession

                2016-08-23 21:36:34,089 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.afterCompletion - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1665555961 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@63465df9

                2016-08-23 21:36:34,089 TRACE [com.arjuna.ats.jta] (default task-2) SynchronizationImple.afterCompletion - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 569373618 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@21eff3b2

                2016-08-23 21:36:34,089 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 removing TSThread:1

                2016-08-23 21:36:34,089 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:17 removing TSThread:1 result = true

                2016-08-23 21:36:34,089 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:17 status: ActionStatus.COMMITTED )

                2016-08-23 21:36:34,089 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.suspend

                2016-08-23 21:36:34,089 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImpleManager.resume

                2016-08-23 21:36:34,090 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e adding Thread[default task-2,5,main]

                2016-08-23 21:36:34,090 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e adding Thread[default task-2,5,main] result = true

                2016-08-23 21:36:34,093 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:34,093 TRACE [com.arjuna.ats.jta] (default task-2) BaseTransaction.commit

                2016-08-23 21:36:34,093 TRACE [com.arjuna.ats.jta] (default task-2) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:34,093 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:e

                2016-08-23 21:36:34,093 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:e) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:34,093 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e removing TSThread:1

                2016-08-23 21:36:34,093 TRACE [com.arjuna.ats.arjuna] (default task-2) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:e removing TSThread:1 result = true

                2016-08-23 21:36:34,093 TRACE [com.arjuna.ats.arjuna] (default task-2) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:e status: ActionStatus.COMMITTED )

                2016-08-23 21:36:39,845 INFO  [stdout] (default task-3)

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3) EVENT

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3)  SEVERITY: 2

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3)  MESSAGE: cvc-complex-type.2.1: Element '' must have no character or element information item [children], because the type's content type is empty.

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3)  LINKED EXCEPTION: null

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3)  LOCATOR

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3)  LINE NUMBER: -1

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3)  COLUMN NUMBER: -1

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3)  OFFSET: -1

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3)  OBJECT: null

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3)  NODE: null

                2016-08-23 21:36:39,846 INFO  [stdout] (default task-3)  URL: null

                 

                 

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.jta] (default task-3) BaseTransaction.begin

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::BasicAction()

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:20

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:20

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:20, 1)

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:20 adding Thread[default task-3,5,main]

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:20 adding Thread[default task-3,5,main] result = true

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:20 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:20 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImpleManager.suspend

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:20 removing TSThread:2

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:20 removing TSThread:2 result = true

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.jta] (default task-3) BaseTransaction.begin

                2016-08-23 21:36:39,847 TRACE [com.arjuna.ats.arjuna] (default task-3) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::BasicAction()

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:21

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:21

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.arjuna] (default task-3) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.arjuna] (default task-3) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:21, 1)

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:21 adding Thread[default task-3,5,main]

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:21 adding Thread[default task-3,5,main] result = true

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.arjuna] (default task-3) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:21 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.arjuna] (default task-3) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:21 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.registerSynchronization - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 915093247 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@368b36ff

                2016-08-23 21:36:39,848 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: created entity manager session TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:21 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.registerInterposedSynchronization - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 944561758 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@384cde5e

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.equals

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,848 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'GeneralCustomizing.getCustomizingValueByGeneralCustomizingId' took 0ms

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,848 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.registerSynchronization - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1014193551 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@3c735d8f

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.enlistResource ( LocalXAResourceImpl@578bf676[connectionListener=4ea62691 connectionManager=a1ecf04 warned=false currentXid=null productName=Microsoft SQL Server productVersion=11.00.3513 jndiName=java:/veri95] )

                2016-08-23 21:36:39,849 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,850 TRACE [com.arjuna.ats.arjuna] (default task-3) StateManager::StateManager( 0:0:0:0:1 )

                2016-08-23 21:36:39,850 TRACE [com.arjuna.ats.arjuna] (default task-3) AbstractRecord::AbstractRecord (0:0:0:0:1)

                2016-08-23 21:36:39,850 TRACE [com.arjuna.ats.arjuna] (default task-3) LastResourceRecord()

                2016-08-23 21:36:39,850 TRACE [com.arjuna.ats.arjuna] (default task-3) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/LastResourceRecord for 0:0:0:0:1

                2016-08-23 21:36:39,850 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,850 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) BaseTransaction.commit

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.beforeCompletion - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 915093247 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@368b36ff

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.beforeCompletion - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1014193551 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@3c735d8f

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.beforeCompletion - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 944561758 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@384cde5e

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.delistResource ( LocalXAResourceImpl@578bf676[connectionListener=4ea62691 connectionManager=a1ecf04 warned=false currentXid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffffc0a80165:3d9ea16:57bca588:21, node_name=1, branch_uid=0:ffffc0a80165:3d9ea16:57bca588:25, subordinatenodename=null, eis_name=java:/veri95 > productName=Microsoft SQL Server productVersion=11.00.3513 jndiName=java:/veri95], 67108864 )

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:21

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::onePhaseCommit() for action-id 0:ffffc0a80165:3d9ea16:57bca588:21

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) LastResourceRecord::topLevelPrepare() for 0:0:0:0:1

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) LastResourceRecord::topLevelCommit() for 0:0:0:0:1

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:21) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.afterCompletion - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 944561758 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@384cde5e

                2016-08-23 21:36:39,851 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: closing entity managersession

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.afterCompletion - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1014193551 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@3c735d8f

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.afterCompletion - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 915093247 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@368b36ff

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:21 removing TSThread:2

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:21 removing TSThread:2 result = true

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:21 status: ActionStatus.COMMITTED )

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.jta] (default task-3) BaseTransaction.begin

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) StateManager::StateManager( 2, 0 )

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::BasicAction()

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::Begin() for action-id 0:ffffc0a80165:3d9ea16:57bca588:26

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::actionInitialise() for action-id 0:ffffc0a80165:3d9ea16:57bca588:26

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) ActionHierarchy::ActionHierarchy(1)

                2016-08-23 21:36:39,851 TRACE [com.arjuna.ats.arjuna] (default task-3) ActionHierarchy::add(0:ffffc0a80165:3d9ea16:57bca588:26, 1)

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:26 adding Thread[default task-3,5,main]

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:26 adding Thread[default task-3,5,main] result = true

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.arjuna] (default task-3) TransactionReaper::insert ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.arjuna] (default task-3) ReaperElement::ReaperElement ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING, 600 )

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.registerSynchronization - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 506472578 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@1e302882

                2016-08-23 21:36:39,852 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: created entity manager session TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.registerInterposedSynchronization - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 1139895489 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@43f16cc1

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.equals

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateCreate' took 0ms

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.registerSynchronization - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1971299371 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@757fa42b

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.putResource

                2016-08-23 21:36:39,852 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,853 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,853 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,853 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.enlistResource ( LocalXAResourceImpl@578bf676[connectionListener=4ea62691 connectionManager=a1ecf04 warned=false currentXid=null productName=Microsoft SQL Server productVersion=11.00.3513 jndiName=java:/veri95] )

                2016-08-23 21:36:39,853 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,853 TRACE [com.arjuna.ats.arjuna] (default task-3) StateManager::StateManager( 0:0:0:0:1 )

                2016-08-23 21:36:39,853 TRACE [com.arjuna.ats.arjuna] (default task-3) AbstractRecord::AbstractRecord (0:0:0:0:1)

                2016-08-23 21:36:39,853 TRACE [com.arjuna.ats.arjuna] (default task-3) LastResourceRecord()

                2016-08-23 21:36:39,853 TRACE [com.arjuna.ats.arjuna] (default task-3) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/LastResourceRecord for 0:0:0:0:1

                2016-08-23 21:36:39,853 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,853 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,854 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,854 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,854 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,854 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,854 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,854 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateReplace' took 0ms

                2016-08-23 21:36:39,854 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,854 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,855 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,855 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,855 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,855 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,855 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,855 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,855 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,857 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,857 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'DatabaseQueue.countByObjectNameByObjectID' took 0ms

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,857 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,858 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,858 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,858 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,858 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,858 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,858 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,858 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'Person.getPersonByPersonID' took 0ms

                2016-08-23 21:36:39,859 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,859 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,859 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,859 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,859 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,859 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,859 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,859 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,859 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,861 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,861 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateCreate' took 0ms

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,861 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,863 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,863 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateReplace' took 0ms

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,863 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,867 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,867 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateCreate' took 0ms

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,867 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,868 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,869 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,869 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'ObjectBehaviorOnUpdate.getGlobalBehaviorOnUpdateReplace' took 0ms

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,869 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,870 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,870 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'DatabaseQueue.countByObjectNameByObjectID' took 0ms

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,870 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,871 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,871 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'Person.getPersonByPersonID' took 0ms

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,871 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,872 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,872 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,872 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,872 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,872 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,872 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'DatabaseQueue.countByObjectNameByObjectID' took 0ms

                2016-08-23 21:36:39,872 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,872 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,872 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,872 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,872 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,872 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,873 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,873 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'Person.getPersonByPersonID' took 0ms

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,873 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,874 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,874 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'HierarchyScope.getHierarchyScopeByPath' took 0ms

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,874 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,875 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,875 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,875 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,875 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,875 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,876 TRACE [org.jboss.as.jpa] (default task-3) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.person.Person' took 1ms

                2016-08-23 21:36:39,876 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,876 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,876 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,876 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,876 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,876 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'GeneralCustomizing.getGeneralCustomizingByGeneralCustomizingIdByCustomizingValue' took 0ms

                2016-08-23 21:36:39,876 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getTransactionKey

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,877 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,878 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,879 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,879 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,879 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,879 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,879 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'DatabaseQueue.countByObjectNameByObjectID' took 1ms

                2016-08-23 21:36:39,879 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,879 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,880 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,880 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,880 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,880 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,880 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,880 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'PersonnelClass.getPersonnelClassByPersonnelClassID' took 0ms

                2016-08-23 21:36:39,880 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,880 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,881 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,881 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,881 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,881 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,881 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,882 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.registerSynchronization - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 2088048218 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@7c75165a

                2016-08-23 21:36:39,882 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,883 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,884 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,884 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,886 TRACE [org.jboss.as.jpa] (default task-3) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 5ms

                2016-08-23 21:36:39,887 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,887 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,887 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,887 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,887 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,887 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'DatabaseQueue.countByObjectNameByObjectID' took 0ms

                2016-08-23 21:36:39,889 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,889 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,890 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,890 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,891 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,891 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,891 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,891 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,891 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,891 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'PersonnelClass.getPersonnelClassByPersonnelClassID' took 0ms

                2016-08-23 21:36:39,891 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,891 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,892 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,892 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,892 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,892 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,892 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,892 TRACE [org.jboss.as.jpa] (default task-3) createNamedQuery name 'HierarchyScope.getHierarchyScopeByPath' took 0ms

                2016-08-23 21:36:39,892 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,892 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,893 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,893 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,893 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,893 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,893 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,893 TRACE [org.jboss.as.jpa] (default task-3) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.personnelClass.PersonnelClass' took 0ms

                2016-08-23 21:36:39,893 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,893 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,894 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,894 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,894 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,894 TRACE [org.jboss.as.jpa] (default task-3) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.person.Person' took 1ms

                2016-08-23 21:36:39,895 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,895 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,897 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,897 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,897 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,897 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,897 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,897 TRACE [org.jboss.as.jpa] (default task-3) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.person.PersonProperty' took 0ms

                2016-08-23 21:36:39,897 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,897 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,897 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,897 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,897 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,898 TRACE [org.jboss.as.jpa] (default task-3) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.person.PersonProperty' took 1ms

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,898 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,898 TRACE [org.jboss.as.jpa] (default task-3) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.person.PersonProperty' took 0ms

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,898 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,898 TRACE [org.jboss.as.jpa] (default task-3) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.person.PersonProperty' took 0ms

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionSynchronizationRegistryImple.getResource

                2016-08-23 21:36:39,898 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,898 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.RUNNING >

                2016-08-23 21:36:39,898 TRACE [org.jboss.as.jpa] (default task-3) merge entityClass 'inxites.be.veri95.ejb.entity.personnel.person.PersonProperty' took 0ms

                2016-08-23 21:36:39,899 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,899 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,900 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,900 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,900 TRACE [com.arjuna.ats.jta] (default task-3) BaseTransaction.commit

                2016-08-23 21:36:39,900 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:39,900 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.beforeCompletion - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 506472578 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@1e302882

                2016-08-23 21:36:39,900 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.beforeCompletion - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1971299371 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@757fa42b

                2016-08-23 21:36:39,900 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,901 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,901 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,901 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,901 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,902 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,902 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,902 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,902 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,903 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,903 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,903 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,903 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,904 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,904 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,904 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.beforeCompletion - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 2088048218 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@7c75165a

                2016-08-23 21:36:39,904 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.beforeCompletion - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 1139895489 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@43f16cc1

                2016-08-23 21:36:39,905 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,905 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,905 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.delistResource ( LocalXAResourceImpl@578bf676[connectionListener=4ea62691 connectionManager=a1ecf04 warned=false currentXid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffffc0a80165:3d9ea16:57bca588:26, node_name=1, branch_uid=0:ffffc0a80165:3d9ea16:57bca588:2a, subordinatenodename=null, eis_name=java:/veri95 > productName=Microsoft SQL Server productVersion=11.00.3513 jndiName=java:/veri95], 67108864 )

                2016-08-23 21:36:39,905 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,905 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:26

                2016-08-23 21:36:39,905 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::onePhaseCommit() for action-id 0:ffffc0a80165:3d9ea16:57bca588:26

                2016-08-23 21:36:39,905 TRACE [com.arjuna.ats.arjuna] (default task-3) LastResourceRecord::topLevelPrepare() for 0:0:0:0:1

                2016-08-23 21:36:39,905 TRACE [com.arjuna.ats.arjuna] (default task-3) LastResourceRecord::topLevelCommit() for 0:0:0:0:1

                2016-08-23 21:36:39,905 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:26) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:39,906 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.afterCompletion - Class: class org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList HashCode: 1139895489 toString: org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@43f16cc1

                2016-08-23 21:36:39,906 DEBUG [org.jboss.as.jpa] (default task-3) default task-3:transaction scoped EntityManager [veri95app.ear#VERI95]: closing entity managersession

                2016-08-23 21:36:39,906 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.afterCompletion - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 2088048218 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@7c75165a

                2016-08-23 21:36:39,906 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.afterCompletion - Class: class org.eclipse.persistence.transaction.JTASynchronizationListener HashCode: 1971299371 toString: org.eclipse.persistence.transaction.JTASynchronizationListener@757fa42b

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.jta] (default task-3) SynchronizationImple.afterCompletion - Class: class org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1 HashCode: 506472578 toString: org.eclipse.persistence.internal.jpa.transaction.JTATransactionWrapper$1@1e302882

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:26 removing TSThread:2

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:26 removing TSThread:2 result = true

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.arjuna] (default task-3) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:26 status: ActionStatus.COMMITTED )

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImpleManager.suspend

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImpleManager.resume

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:20 adding Thread[default task-3,5,main]

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::addChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:20 adding Thread[default task-3,5,main] result = true

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.jta] (default task-3) BaseTransaction.commit

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.jta] (default task-3) TransactionImple.commitAndDisassociate

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::End() for action-id 0:ffffc0a80165:3d9ea16:57bca588:20

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::End() result for action-id (0:ffffc0a80165:3d9ea16:57bca588:20) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:20 removing TSThread:2

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.arjuna] (default task-3) BasicAction::removeChildThread () action 0:ffffc0a80165:3d9ea16:57bca588:20 removing TSThread:2 result = true

                2016-08-23 21:36:39,908 TRACE [com.arjuna.ats.arjuna] (default task-3) TransactionReaper::remove ( BasicAction: 0:ffffc0a80165:3d9ea16:57bca588:20 status: ActionStatus.COMMITTED )

                • 5. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                  smarlow

                  I would like to see more TRACE logging for org.jboss.as.jpa that might help diagnose weaving issues.  Perhaps we should add that now.  Just to give me a hint if that is the right direction, could you let me know where the

                  the persistence.xml is in your ear and where are the entity classes? 

                  • 6. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                    christopher.j.willems

                    hi,

                     

                    below is the project structure the persistence.xml is in the jpa project . what trace do you want ? just normal operations ?

                    project structure.JPG

                    • 7. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                      smarlow

                      Hmm, so all of the entity classes are also in the veri95jpa.jar with the persistence.xml.  From a TRACE perspective, I'd like to add some more trace logging to the JPA container in WildFly around when the weaving should happen.  I'm not really sure of what weaving related TRACE logging is already in EclipseLink that could be enabled.  If you create a WFLY jira, I'll add the additional WildFly trace that lets us know which application classes can be transformed/weaved/rewritten/enhanced during deployment.

                       

                      Another option is that you could debug with the EclipseLink source to see what is or isn't happening exactly with EclipseLink weaving.  Or you could debug the WildFly source (during deployment) to verify that the weaving is happening, that might be easier than debugging EclipseLink. 

                      • 8. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                        christopher.j.willems

                        ok,

                         

                        i created WFLY-6998 problem with lazy relationship and eclipselink 2.6.3 on wildfly 10 final.

                        please notify the eclipselink is now 2.6.3 and the JVM starts with eclipselink as agent and logging for eclipselink is on. I also build using

                        <plugin>

                                    <groupId>de.empulse.eclipselink</groupId>

                                    <artifactId>staticweave-maven-plugin</artifactId>

                               ....

                         

                        there is a big log attached and the end is the most interesting , you have "registered to be processed by weaver." for all relationships , an example of a problem is the LinkPersonnelClassPersonDefinedBy.

                         

                        if you tell me where to debug i will .

                        • 9. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                          smarlow

                          Looks like the EclipseLink trace logging that you enabled is better than I expected, as it shows which Java entity classes have been weaved.  It also looks you are persisting the LinkPersonnelClassPersonDefinedBy class which appears to be associated with an entity manager that is joined to the JTA transaction.

                           

                          2016-08-24 13:15:23,004 TRACE [org.jboss.as.jpa] (default task-12) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 3ms

                          2016-08-24 13:16:30,840 TRACE [org.jboss.as.jpa] (default task-3) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 4ms

                          2016-08-24 15:39:08,822 TRACE [org.jboss.as.jpa] (default task-4) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 4ms

                          2016-08-24 15:54:38,801 TRACE [org.jboss.as.jpa] (default task-3) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 5ms

                          2016-08-24 16:04:09,875 TRACE [org.jboss.as.jpa] (default task-3) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 3ms

                          2016-08-24 16:05:57,121 TRACE [org.jboss.as.jpa] (default task-5) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 5ms

                          2016-08-24 16:17:32,465 TRACE [org.jboss.as.jpa] (default task-3) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 7ms

                          2016-08-24 16:51:43,243 TRACE [org.jboss.as.jpa] (default task-3) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 7ms

                          2016-08-24 16:53:10,449 TRACE [org.jboss.as.jpa] (default task-3) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 8ms

                          2016-08-24 17:20:23,113 TRACE [org.jboss.as.jpa] (default task-4) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 4ms

                          2016-08-24 17:29:23,066 TRACE [org.jboss.as.jpa] (default task-3) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 5ms

                          2016-08-24 17:32:39,189 TRACE [org.jboss.as.jpa] (default task-3) persist entityClass 'inxites.be.veri95.ejb.entity.personnel.common.LinkPersonnelClassPersonDefinedBy' took 6ms

                          [s

                           

                          Just to be sure that the entity manager is joined to the transaction, since your earlier example code (PersonXMLServiceCore) is using UserTransaction, could you also call EntityManager.joinTransaction() when doing the existingDefinedBy.addAll(personnelClasses). 

                          • 10. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                            christopher.j.willems

                            hi,

                             

                            em.joinTransaction(); has no effect , getting the relationship from the database again with a query finds the relationship as is doing em.refresh() but that kills performance ... we need the laziness ...

                             

                            i attached the logs in jira

                            • 11. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                              smarlow

                              em.joinTransaction(); has no effect , getting the relationship from the database again with a query finds the relationship as is doing em.refresh() but that kills performance ... we need the laziness ...

                               

                              You mentioned before that the relationship only disappears after restarting the server, is that still the case?  I assume that your doing the em.refresh only if the relationship is null, as if it needs to be added again but really, the lazy fetch didn't happen, as your finding that a refresh finds the missing relationship. 

                               

                              Are you manually updating the relationship from both sides? 

                               

                              Also, why are you using fetch = FetchType.EAGER, should that instead be fetch = FetchType.LAZY?

                              • 12. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                                christopher.j.willems

                                hi ,

                                 

                                yes , after restart the relationship is available until the first transaction commit . Relationships newly created will stay available , probably because they are persisted and loaded into memory.

                                 

                                the relationships from the example are many to many between person and personnelClass , so from person I load lazy because I can have many personnelClasses and vice versa . the relationship table itself I load eager because there it's sure that I will have only 1 person and 1 personnelClass. normally i persist the relationship and manually update the relationship from both sides and merge both sides . em.refresh is never used for performance reasons , i used it for testing .

                                 

                                but in the end this is just an example , i have 100rds of entities and 1000nds of relationships, the issue is everywhere and testusers are experiencing strange effects .

                                • 13. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                                  smarlow

                                  Hi,

                                   

                                  Is the (JPA related) application code written exactly the same on WildFly as it is on the other application servers?  I'm just curious if that could possibly be a possible cause, because the next question is probably more difficult to answer, as I'm not sure why you are seeing the difference between WildFly and other app servers.

                                   

                                  My next question is probably the same as yours, how can more insight be obtained as to why the relationship is only available until the first transaction commit.  It might make sense to reproduce the problem with a small test that can be run on WildFly and other app servers to see if the EclipseLink trace output gives any insight as to what is occurring that causes the relationship to not be loaded in memory (even though an em.refresh would find it in the database).  I'm guessing that some internal EclipseLink state flag in the weaved entity class code, is getting confused for some reason.

                                  • 14. Re: problem with lazy relationship and eclipselink 2.5.2 on wildfly 10 final
                                    christopher.j.willems

                                    hi

                                     

                                    the coding is the same and even jpa 1.0 compliant due to SAP netweaver ...

                                     

                                    Glassfish 3.1 runs also the same , I think it's best to compare with Glassfish, SAP netweaver  is not really something you want to get into ;-). So you have the traces you want from Wildfly ?

                                    1 2 Previous Next