Showing posts with label JMS. Show all posts
Showing posts with label JMS. Show all posts

Friday, January 23, 2026

Building Jakarta EE JMS MDB project for WebLogic Server 14.1.2 with Maven

 

HOWTO


See also

Git



Create Java EE project using Maven archetype


dave@dave:/git/weblogic/dave-basic-project-14.1.2$ mvn archetype:generate     -DarchetypeGroupId=com.oracle.weblogic.archetype     -DarchetypeArtifactId=basic-mdb     -DarchetypeVersion=14.1.2-0-0     -DgroupId=dave     -DartifactId=dave-basic-mdb-project     -Dversion=1.0-SNAPSHOT
[INFO] Scanning for projects...
[INFO] 
[INFO] ------------------< org.apache.maven:standalone-pom >-------------------
[INFO] Building Maven Stub Project (No POM) 1
[INFO] --------------------------------[ pom ]---------------------------------
[INFO] 
[INFO] >>> archetype:3.4.1:generate (default-cli) > generate-sources @ standalone-pom >>>
[INFO] 
[INFO] <<< archetype:3.4.1:generate (default-cli) < generate-sources @ standalone-pom <<<
[INFO] 
[INFO] 
[INFO] --- archetype:3.4.1:generate (default-cli) @ standalone-pom ---
D[INFO] Generating project in Interactive mode
Downloading from central: https://repo.maven.apache.org/maven2/archetype-catalog.xml
Downloaded from central: https://repo.maven.apache.org/maven2/archetype-catalog.xml (18 MB at 57 MB/s)
[WARNING] Archetype not found in any catalog. Falling back to central repository.
[WARNING] Add a repository with id 'archetype' in your settings.xml if archetype's repository is elsewhere.
[INFO] Using property: groupId = dave
[INFO] Using property: artifactId = dave-basic-mdb-project
[INFO] Using property: version = 1.0-SNAPSHOT
[INFO] Using property: package = dave
Confirm properties configuration:
groupId: dave
artifactId: dave-basic-mdb-project
version: 1.0-SNAPSHOT
package: dave
 Y: 
[INFO] ----------------------------------------------------------------------------
[INFO] Using following parameters for creating project from Archetype: basic-mdb:14.1.2-0-0
[INFO] ----------------------------------------------------------------------------
[INFO] Parameter: groupId, Value: dave
[INFO] Parameter: artifactId, Value: dave-basic-mdb-project
[INFO] Parameter: version, Value: 1.0-SNAPSHOT
[INFO] Parameter: package, Value: dave
[INFO] Parameter: packageInPathFormat, Value: dave
[INFO] Parameter: package, Value: dave
[INFO] Parameter: groupId, Value: dave
[INFO] Parameter: artifactId, Value: dave-basic-mdb-project
[INFO] Parameter: version, Value: 1.0-SNAPSHOT
[INFO] Project created from Archetype in dir: /git/weblogic/dave-basic-project-14.1.2/dave-basic-mdb-project
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  7.442 s
[INFO] Finished at: 2026-01-23T20:47:42+01:00
[INFO] ------------------------------------------------------------------------


Send to queue 

  @Resource(mappedName = "myConnectionFactory")
  private ConnectionFactory connectionFactory;

  @Resource(mappedName = "myJmsQueue")
  private Queue accountQueue;

  public void depositJms() throws JMSException{
    try{
      javax.jms.Connection connection = connectionFactory.createConnection();
      Session accountSession = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
      MessageProducer messageProducer = accountSession.createProducer(accountQueue);
      
      Message message = accountSession.createMessage();
      message.setStringProperty("name", name);
      message.setFloatProperty("amount", amount);
      
      messageProducer.send(message);
    } catch (JMSException e) {
      e.printStackTrace();
      throw e;
    }
    
    msg = "A message with the deposit request has been sent, please check the console output of the server to verify it was received";
  }

MDB



package dave.jms.destination;

import java.text.NumberFormat;
import javax.annotation.Resource;
import javax.ejb.ActivationConfigProperty;
import javax.ejb.MessageDriven;
import javax.ejb.MessageDrivenContext;
import javax.jms.Message;
import javax.jms.MessageListener;

/**
 * @author Copyright (c) 2011,2013, Oracle and/or its affiliates. All rights reserved.
 *
 * Message driven bean used to process messages.
 */

@MessageDriven(
  mappedName = "myJmsQueue",
  activationConfig = {
    @ActivationConfigProperty(
      propertyName  = "destinationType", 
      propertyValue = "javax.jms.Queue"),   
      
    @ActivationConfigProperty(
      propertyName  = "acknowledgeMode",
      propertyValue = "Auto-acknowledge")
  }
)
public class QueueMDB implements MessageListener {
    
  private final NumberFormat currencyFormatter = NumberFormat.getCurrencyInstance();    
  
  @Resource
  private MessageDrivenContext mdctx;
  
  public QueueMDB() {
    
  }
  
  public void onMessage(Message message) {
    try{
      System.out.println("The money has been deposited to " + message.getStringProperty("name") +  ", for the amount of " + currencyFormatter.format(message.getFloatProperty("amount")));
        
    } catch (Exception e) {
      e.printStackTrace();
      mdctx.setRollbackOnly();
    }
  }

}


List Weblogic JMS queue configuration 

  /app/weblogic-14.1.2/oracle_common/common/bin/wlst.sh src/main/scripts/list_queue_attrs.py

Initializing WebLogic Scripting Tool (WLST) ...

Welcome to WebLogic Server Administration Scripting Shell

Type help() for help on available commands

Connecting to t3://127.0.0.1:7001 with userid weblogic ...
Successfully connected to Admin Server "AdminServer" that belongs to domain "dave_domain".

Warning: An insecure protocol was used to connect to the server. 
To ensure on-the-wire security, the SSL port or Admin port should be used instead.

Location changed to edit tree.   
This is a writable tree with DomainMBean as the root.    
To make changes you will need to start an edit session via startEdit(). 
For more help, use help('edit').
You already have an edit session in progress and hence WLST will 
continue with your edit session.

Starting an edit session ...
Started edit session, be sure to save and activate your changes once you are done.
dr--   DeliveryFailureParams
dr--   DeliveryParamsOverrides
dr--   MessageLoggingParams
dr--   Quota
dr--   Template
dr--   Thresholds

-rw-   AttachSender                                 supports
-rw-   ConsumptionPausedAtStartup                   false
-rw-   DefaultTargetingEnabled                      false
-rw-   DefaultUnitOfOrder                           false
-rw-   DestinationKeys                              null
-rw-   ForwardDelay                                 -1
-r--   Id                                           0
-rw-   IncompleteWorkExpirationTime                 -1
-rw-   InsertionPausedAtStartup                     false
-rw-   JMSCreateDestinationIdentifier               null
-rw-   JNDIName                                     myJmsQueue
-rw-   LoadBalancingPolicy                          Round-Robin
-rw-   LocalJNDIName                                null
-rw-   MaximumMessageSize                           2147483647
-rw-   MessagingPerformancePreference               25
-rw-   Name                                         myJmsQueue
-rw-   Notes                                        null
-rw-   ProductionPausedAtStartup                    false
-rw-   Quota                                        null
-rw-   ResetDeliveryCountOnForward                  true
-rw-   SAFExportPolicy                              All
-rw-   SubDeploymentName                            subDep
-rw-   Template                                     null
-rw-   UnitOfOrderRouting                           Hash
-rw-   UnitOfWorkHandlingPolicy                     PassThrough

-r-x   addDestinationKey                            Void : String(destinationKey)
-r-x   isSet                                        Boolean : String(propertyName)
-r-x   removeDestinationKey                         Void : String(destinationKey)
-r-x   unSet                                        Void : String(propertyName)

Edit session is cancelled successfully.
Disconnected from weblogic server: AdminServer


Exiting WebLogic Scripting Tool.

Enable JMS logging 

$ cat   /app/weblogic-14.1.2/oracle_common/common/bin/wlst.sh src/main/scripts/enable_logging_final.py
#!/bin/sh

SCRIPTNAME=$0
SCRIPTPATH=`dirname "${SCRIPTNAME}"`
MW_HOME=`cd "${SCRIPTPATH}/../../.." ; pwd`
export MW_HOME
# Delegate to the common delegation script ...
"${SCRIPTPATH}/fmwconfig_common.sh" wlst_internal.sh "$@"


try:
    connect('weblogic', 'weblogic123', 't3://127.0.0.1:7001')
    edit()
    startEdit()
    
    queuePath = '/JMSSystemResources/myJmsSystemResource/JMSResource/myJmsSystemResource/Queues/myJmsQueue/MessageLoggingParams/myJmsQueue'
    
    print("Navigating to MessageLoggingParams...")
    try:
        cd(queuePath)
    except:
        print("Direct path failed, trying list...")
        cd('/JMSSystemResources/myJmsSystemResource/JMSResource/myJmsSystemResource/Queues/myJmsQueue/MessageLoggingParams')
        ls()
        # Assume the single child is the one we want
        # In WLST, sometimes we need to pick the specific name if it wasn't auto-named
        kids = cmo.getMessageLoggingParams()
        # But in edit tree we cd.
        # Let's try cd to the first child found in ls() if possible, but manual is safer
        cd('myJmsQueue')
        
    print("Enabling Message Logging...")
    cmo.setMessageLoggingEnabled(True)
    cmo.setMessageLoggingFormat("%header%,%properties%")
    
    save()
    activate()
    print("JMS Queue Message Logging enabled successfully.")
    
except Exception as e:
    print("Error: " + str(e))
    cancelEdit('y')
    exit(exitcode=1)

disconnect()
exit()

Show JMS log 


dave@dave:/git/weblogic/dave-basic-project-14.1.2/dave-basic-webapp-ejb-project$  ls -l /app/domains/dave_domain/servers/AdminServer/logs/jmsservers/myJMSServer/
total 4
-rw-r-----. 1 dave dave 2389 Jan 23 23:07 myJMSServer-jms.messages.log
dave@dave:/git/weblogic/dave-basic-project-14.1.2/dave-basic-webapp-ejb-project$  tail -n 20 /app/domains/dave_domain/servers/AdminServer/logs/jmsservers/myJMSServer/myJMSServer-jms.messages.log
####<Jan 23, 2026, 11:07:31,902 PM Central European Standard Time> <> <> <1769206051902> <116244> <ID:<974816.1769206051889.0>> <> <myJmsSystemResource!myJmsQueue> <Produced> <weblogic> <> <&lt;?xml version="1.0" encoding="UTF-8"?&gt;
&lt;mes:WLJMSMessage xmlns:mes="http://www.bea.com/WLS/JMS/Message"&gt;&lt;mes:Header&gt;&lt;mes:JMSDeliveryMode&gt;PERSISTENT&lt;/mes:JMSDeliveryMode&gt;&lt;mes:JMSExpiration&gt;0&lt;/mes:JMSExpiration&gt;&lt;mes:JMSPriority&gt;4&lt;/mes:JMSPriority&gt;&lt;mes:JMSRedelivered&gt;false&lt;/mes:JMSRedelivered&gt;&lt;mes:JMSTimestamp&gt;1769206051889&lt;/mes:JMSTimestamp&gt;&lt;mes:Properties&gt;&lt;mes:property name="amount"&gt;&lt;mes:Float&gt;100.5&lt;/mes:Float&gt;&lt;/mes:property&gt;&lt;mes:property name="name"&gt;&lt;mes:String&gt;john.doe&lt;/mes:String&gt;&lt;/mes:property&gt;&lt;mes:property name="JMS_BEA_DeliveryTime"&gt;&lt;mes:Long&gt;1769206051889&lt;/mes:Long&gt;&lt;/mes:property&gt;&lt;mes:property name="JMSXDeliveryCount"&gt;&lt;mes:Int&gt;0&lt;/mes:Int&gt;&lt;/mes:property&gt;&lt;/mes:Properties&gt;&lt;/mes:Header&gt;&lt;/mes:WLJMSMessage&gt;> <> 
####<Jan 23, 2026, 11:07:31,967 PM Central European Standard Time> <BEA1-64B3874E479C50BE51E2-574C53746F72655F646176655F646F6D61696E5F5F574C535F41646D696E536572766572> <> <1769206051967> <308200> <ID:<974816.1769206051889.0>> <> <myJmsSystemResource!myJmsQueue> <Consumed> <<anonymous>> <MC:CA(local):OAMI(AdminServer.jms.connection30.session74.consumer76)> <&lt;?xml version="1.0" encoding="UTF-8"?&gt;
&lt;mes:WLJMSMessage xmlns:mes="http://www.bea.com/WLS/JMS/Message"&gt;&lt;mes:Header&gt;&lt;mes:JMSDeliveryMode&gt;PERSISTENT&lt;/mes:JMSDeliveryMode&gt;&lt;mes:JMSExpiration&gt;0&lt;/mes:JMSExpiration&gt;&lt;mes:JMSPriority&gt;4&lt;/mes:JMSPriority&gt;&lt;mes:JMSRedelivered&gt;false&lt;/mes:JMSRedelivered&gt;&lt;mes:JMSTimestamp&gt;1769206051889&lt;/mes:JMSTimestamp&gt;&lt;mes:Properties&gt;&lt;mes:property name="amount"&gt;&lt;mes:Float&gt;100.5&lt;/mes:Float&gt;&lt;/mes:property&gt;&lt;mes:property name="name"&gt;&lt;mes:String&gt;john.doe&lt;/mes:String&gt;&lt;/mes:property&gt;&lt;mes:property name="JMS_BEA_DeliveryTime"&gt;&lt;mes:Long&gt;1769206051889&lt;/mes:Long&gt;&lt;/mes:property&gt;&lt;mes:property name="JMSXDeliveryCount"&gt;&lt;mes:Int&gt;1&lt;/mes:Int&gt;&lt;/mes:property&gt;&lt;/mes:Properties&gt;&lt;/mes:Header&gt;&lt;/mes:WLJMSMessage&gt;> <> 
dave@dave:/git/weblogic/dave-basic-project-14.1.2/dave-basic-webapp-ejb-project$
Posted by at No comments:
Labels: , , , ,

Tuesday, March 17, 2015

JBoss Wildfly 8.2 JMS configuration - JTA, HornetQ

Using JBoss Wildfly quickstart https://github.com/wildfly/quickstart/tree/master/jta-crash-rec

Start server in full mode
[dave@localhost bin]$ ./standalone.sh -c standalone-full.xml
=========================================================================

  JBoss Bootstrap Environment

  JBOSS_HOME: /app/wildfly-8.2.0.Final

  JAVA: /usr/java/jdk1.7.0_60/bin/java

  JAVA_OPTS:  -server -Xms64m -Xmx512m -XX:MaxPermSize=256m -Djava.net.preferIPv4Stack=true -Djboss.modules.system.pkgs=org.jboss.byteman -Djava.awt.headless=true
Deploy quickstart jta-crash-rec 
[dave@localhost quickstart-master]$ cd jta-crash-rec/
[dave@localhost jta-crash-rec]$ pwd
/home/dave/workspace/quickstart-master/jta-crash-rec
[dave@localhost jta-crash-rec]$  mvn install wildfly:deploy

Configure debug logging on JTA Arjuna module

Access the quickstart 
http://localhost:8080/wildfly-jta-crash-rec/XA?key=&value=&submit=Submit
Debug of MessageListener transaction 
23:06:38,342 DEBUG [org.hornetq.core.server] (hornetq-expiry-reaper-thread) Cannot expire from jms.queue.ExpiryQueue into jms.queue.ExpiryQueue
23:06:40,820 DEBUG [org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl] (default task-7) Skipping JTA sync registration due to auto join checking
23:06:40,821 DEBUG [org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl] (default task-7) successfully registered Synchronization
23:06:40,821 DEBUG [org.hibernate.jpa.spi.AbstractEntityManagerImpl] (default task-7) Looking for a JTA transaction to join
23:06:40,821 DEBUG [org.jboss.as.jpa] (default task-7) default task-7:transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: created entity manager session TransactionImple < ac, BasicAction: 0:ffff7f000001:-520944e9:55089cdc:103 status: ActionStatus.RUNNING >
23:06:40,821 DEBUG [org.hibernate.SQL] (default task-7) select kvpair0_.name as name1_0_, kvpair0_.value as value2_0_ from KVPair kvpair0_
23:06:40,822 INFO  [stdout] (default task-7) Hibernate: select kvpair0_.name as name1_0_, kvpair0_.value as value2_0_ from KVPair kvpair0_
23:06:40,822 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-7) Obtaining JDBC connection
23:06:40,822 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-7) Obtained JDBC connection
23:06:40,824 DEBUG [org.hibernate.loader.Loader] (default task-7) Result row: EntityKey[org.jboss.as.quickstarts.xa.KVPair#k15]
23:06:40,824 DEBUG [org.hibernate.engine.internal.TwoPhaseLoad] (default task-7) Resolving associations for [org.jboss.as.quickstarts.xa.KVPair#k15]
23:06:40,824 DEBUG [org.hibernate.engine.internal.TwoPhaseLoad] (default task-7) Done materializing entity [org.jboss.as.quickstarts.xa.KVPair#k15]
23:06:40,824 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-7) Releasing JDBC connection
23:06:40,825 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-7) Released JDBC connection
23:06:40,825 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-7) Processing flush-time cascades
23:06:40,825 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-7) Dirty checking collections
23:06:40,825 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-7) Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
23:06:40,825 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-7) Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
23:06:40,825 DEBUG [org.hibernate.internal.util.EntityPrinter] (default task-7) Listing entities:
23:06:40,826 DEBUG [org.hibernate.internal.util.EntityPrinter] (default task-7) org.jboss.as.quickstarts.xa.KVPair{value=v15 updated via JMS, key=k15}
23:06:40,826 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-7) Releasing JDBC connection
23:06:40,826 DEBUG [org.jboss.as.jpa] (default task-7) default task-7:transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: closing entity managersession
23:06:40,826 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-7) Aggressively releasing JDBC connection
23:06:53,782 DEBUG [org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl] (default task-8) Skipping JTA sync registration due to auto join checking
23:06:53,782 DEBUG [org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl] (default task-8) successfully registered Synchronization
23:06:53,782 DEBUG [org.hibernate.jpa.spi.AbstractEntityManagerImpl] (default task-8) Looking for a JTA transaction to join
23:06:53,783 DEBUG [org.jboss.as.jpa] (default task-8) default task-8:transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: created entity manager session TransactionImple < ac, BasicAction: 0:ffff7f000001:-520944e9:55089cdc:10a status: ActionStatus.RUNNING >
23:06:53,783 DEBUG [org.jboss.as.jpa] (default task-8) default task-8:transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffff7f000001:-520944e9:55089cdc:10a status: ActionStatus.RUNNING >
23:06:53,783 DEBUG [org.hibernate.SQL] (default task-8) select kvpair0_.name as name1_0_0_, kvpair0_.value as value2_0_0_ from KVPair kvpair0_ where kvpair0_.name=?
23:06:53,783 INFO  [stdout] (default task-8) Hibernate: select kvpair0_.name as name1_0_0_, kvpair0_.value as value2_0_0_ from KVPair kvpair0_ where kvpair0_.name=?
23:06:53,783 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Obtaining JDBC connection
23:06:53,785 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Obtained JDBC connection
23:06:53,787 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Releasing JDBC connection
23:06:53,787 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Released JDBC connection
23:06:53,787 DEBUG [org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader] (default task-8) Done entity load : org.jboss.as.quickstarts.xa.KVPair#k16
23:06:53,788 DEBUG [org.jboss.as.jpa] (default task-8) default task-8:transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffff7f000001:-520944e9:55089cdc:10a status: ActionStatus.RUNNING >
23:06:53,788 DEBUG [org.hibernate.event.internal.AbstractSaveEventListener] (default task-8) Generated identifier: k16, using strategy: org.hibernate.id.Assigned
23:06:53,792 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-8) Processing flush-time cascades
23:06:53,793 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-8) Dirty checking collections
23:06:53,793 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-8) Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
23:06:53,793 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-8) Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
23:06:53,794 DEBUG [org.hibernate.internal.util.EntityPrinter] (default task-8) Listing entities:
23:06:53,794 DEBUG [org.hibernate.internal.util.EntityPrinter] (default task-8) org.jboss.as.quickstarts.xa.KVPair{value=v16, key=k16}
23:06:53,794 DEBUG [org.hibernate.SQL] (default task-8) insert into KVPair (value, name) values (?, ?)
23:06:53,795 INFO  [stdout] (default task-8) Hibernate: insert into KVPair (value, name) values (?, ?)
23:06:53,795 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Obtaining JDBC connection
23:06:53,796 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Obtained JDBC connection
23:06:53,797 DEBUG [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-8) Skipping aggressive release due to manual disabling
23:06:53,797 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Releasing JDBC connection
23:06:53,798 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Released JDBC connection
23:06:53,886 DEBUG [org.hornetq.core.server] (Thread-12 (HornetQ-server-HornetQServerImpl::serverUUID=3f93832c-cce0-11e4-85a9-c34d99e66ea7-733564457)) QueueImpl[name=jms.queue.jta-crash-rec-quickstart, postOffice=PostOfficeImpl [server=HornetQServerImpl::serverUUID=3f93832c-cce0-11e4-85a9-c34d99e66ea7]]@57fd577 doing deliver. messageReferences=0
23:06:53,888 DEBUG [org.jboss.as.jpa] (default task-8) default task-8:transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: closing entity managersession
23:06:53,888 DEBUG [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-8) HHH000420: Closing un-released batch
23:06:53,889 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Aggressively releasing JDBC connection
23:06:53,891 DEBUG [org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl] (default task-8) Skipping JTA sync registration due to auto join checking
23:06:53,890 DEBUG [org.hornetq.core.client] (Thread-22 (HornetQ-client-global-threads-141278138)) client ack messageID = 262
23:06:53,891 DEBUG [org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl] (default task-8) successfully registered Synchronization
23:06:53,891 DEBUG [org.hibernate.jpa.spi.AbstractEntityManagerImpl] (default task-8) Looking for a JTA transaction to join
23:06:53,892 DEBUG [org.jboss.as.jpa] (default task-8) default task-8:transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: created entity manager session TransactionImple < ac, BasicAction: 0:ffff7f000001:-520944e9:55089cdc:119 status: ActionStatus.RUNNING >
23:06:53,892 DEBUG [org.hibernate.SQL] (default task-8) select kvpair0_.name as name1_0_, kvpair0_.value as value2_0_ from KVPair kvpair0_
23:06:53,893 INFO  [stdout] (default task-8) Hibernate: select kvpair0_.name as name1_0_, kvpair0_.value as value2_0_ from KVPair kvpair0_
23:06:53,893 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Obtaining JDBC connection
23:06:53,894 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Obtained JDBC connection
23:06:53,896 INFO  [org.jboss.as.quickstarts.xa.DbUpdaterMDB] (Thread-22 (HornetQ-client-global-threads-141278138)) Received Message: HornetQMessage[ID:eb7c1627-ccf1-11e4-a9c4-0776b366296e]:PERSISTENT
23:06:53,896 DEBUG [org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Skipping JTA sync registration due to auto join checking
23:06:53,896 DEBUG [org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) successfully registered Synchronization
23:06:53,896 DEBUG [org.hibernate.jpa.spi.AbstractEntityManagerImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Looking for a JTA transaction to join
23:06:53,897 DEBUG [org.jboss.as.jpa] (Thread-22 (HornetQ-client-global-threads-141278138)) Thread-22 (HornetQ-client-global-threads-141278138):transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: created entity manager session TransactionImple < ac, BasicAction: 0:ffff7f000001:-520944e9:55089cdc:115 status: ActionStatus.RUNNING >
23:06:53,897 DEBUG [org.jboss.as.jpa] (Thread-22 (HornetQ-client-global-threads-141278138)) Thread-22 (HornetQ-client-global-threads-141278138):transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffff7f000001:-520944e9:55089cdc:115 status: ActionStatus.RUNNING >
23:06:53,897 DEBUG [org.hibernate.loader.Loader] (default task-8) Result row: EntityKey[org.jboss.as.quickstarts.xa.KVPair#k15]
23:06:53,897 DEBUG [org.hibernate.SQL] (Thread-22 (HornetQ-client-global-threads-141278138)) select kvpair0_.name as name1_0_0_, kvpair0_.value as value2_0_0_ from KVPair kvpair0_ where kvpair0_.name=?
23:06:53,898 INFO  [stdout] (Thread-22 (HornetQ-client-global-threads-141278138)) Hibernate: select kvpair0_.name as name1_0_0_, kvpair0_.value as value2_0_0_ from KVPair kvpair0_ where kvpair0_.name=?
23:06:53,898 DEBUG [org.hibernate.loader.Loader] (default task-8) Result row: EntityKey[org.jboss.as.quickstarts.xa.KVPair#k16]
23:06:53,898 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Obtaining JDBC connection
23:06:53,899 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Obtained JDBC connection
23:06:53,899 DEBUG [org.hibernate.engine.internal.TwoPhaseLoad] (default task-8) Resolving associations for [org.jboss.as.quickstarts.xa.KVPair#k15]
23:06:53,900 DEBUG [org.hibernate.engine.internal.TwoPhaseLoad] (default task-8) Done materializing entity [org.jboss.as.quickstarts.xa.KVPair#k15]
23:06:53,900 DEBUG [org.hibernate.engine.internal.TwoPhaseLoad] (default task-8) Resolving associations for [org.jboss.as.quickstarts.xa.KVPair#k16]
23:06:53,900 DEBUG [org.hibernate.engine.internal.TwoPhaseLoad] (default task-8) Done materializing entity [org.jboss.as.quickstarts.xa.KVPair#k16]
23:06:53,900 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Releasing JDBC connection
23:06:53,901 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Released JDBC connection
23:06:53,902 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-8) Processing flush-time cascades
23:06:53,902 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-8) Dirty checking collections
23:06:53,902 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-8) Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
23:06:53,903 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-8) Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
23:06:53,903 DEBUG [org.hibernate.loader.plan.exec.process.internal.ResultSetProcessorImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Starting ResultSet row #0
23:06:53,903 DEBUG [org.hibernate.internal.util.EntityPrinter] (default task-8) Listing entities:
23:06:53,903 DEBUG [org.hibernate.loader.plan.exec.process.internal.EntityReferenceInitializerImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) On call to EntityIdentifierReaderImpl#resolve, EntityKey was already known; should only happen on root returns with an optional identifier specified
23:06:53,903 DEBUG [org.hibernate.internal.util.EntityPrinter] (default task-8) org.jboss.as.quickstarts.xa.KVPair{value=v15 updated via JMS, key=k15}
23:06:53,903 DEBUG [org.hibernate.internal.util.EntityPrinter] (default task-8) org.jboss.as.quickstarts.xa.KVPair{value=v16, key=k16}
23:06:53,903 DEBUG [org.hibernate.engine.internal.TwoPhaseLoad] (Thread-22 (HornetQ-client-global-threads-141278138)) Resolving associations for [org.jboss.as.quickstarts.xa.KVPair#k16]
23:06:53,903 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Releasing JDBC connection
23:06:53,904 DEBUG [org.hibernate.engine.internal.TwoPhaseLoad] (Thread-22 (HornetQ-client-global-threads-141278138)) Done materializing entity [org.jboss.as.quickstarts.xa.KVPair#k16]
23:06:53,904 DEBUG [org.jboss.as.jpa] (default task-8) default task-8:transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: closing entity managersession
23:06:53,904 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Releasing JDBC connection
23:06:53,904 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-8) Aggressively releasing JDBC connection
23:06:53,904 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Released JDBC connection
23:06:53,905 DEBUG [org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader] (Thread-22 (HornetQ-client-global-threads-141278138)) Done entity load : org.jboss.as.quickstarts.xa.KVPair#k16
23:06:53,905 DEBUG [org.jboss.as.jpa] (Thread-22 (HornetQ-client-global-threads-141278138)) Thread-22 (HornetQ-client-global-threads-141278138):transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffff7f000001:-520944e9:55089cdc:115 status: ActionStatus.RUNNING >
23:06:53,905 INFO  [org.jboss.as.quickstarts.xa.DbUpdaterMDB] (Thread-22 (HornetQ-client-global-threads-141278138)) JTA Crash Record Quickstart: key value pair updated via JMS
23:06:53,906 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (Thread-22 (HornetQ-client-global-threads-141278138)) Processing flush-time cascades
23:06:53,907 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (Thread-22 (HornetQ-client-global-threads-141278138)) Dirty checking collections
23:06:53,907 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (Thread-22 (HornetQ-client-global-threads-141278138)) Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
23:06:53,908 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (Thread-22 (HornetQ-client-global-threads-141278138)) Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
23:06:53,908 DEBUG [org.hibernate.internal.util.EntityPrinter] (Thread-22 (HornetQ-client-global-threads-141278138)) Listing entities:
23:06:53,908 DEBUG [org.hibernate.internal.util.EntityPrinter] (Thread-22 (HornetQ-client-global-threads-141278138)) org.jboss.as.quickstarts.xa.KVPair{value=v16 updated via JMS, key=k16}
23:06:53,909 DEBUG [org.hibernate.SQL] (Thread-22 (HornetQ-client-global-threads-141278138)) update KVPair set value=? where name=?
23:06:53,909 INFO  [stdout] (Thread-22 (HornetQ-client-global-threads-141278138)) Hibernate: update KVPair set value=? where name=?
23:06:53,909 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Obtaining JDBC connection
23:06:53,910 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Obtained JDBC connection
23:06:53,911 DEBUG [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Skipping aggressive release due to manual disabling
23:06:53,911 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Releasing JDBC connection
23:06:53,912 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Released JDBC connection
23:06:53,977 DEBUG [org.jboss.as.jpa] (Thread-22 (HornetQ-client-global-threads-141278138)) Thread-22 (HornetQ-client-global-threads-141278138):transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: closing entity managersession
23:06:53,977 DEBUG [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) HHH000420: Closing un-released batch
23:06:53,977 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (Thread-22 (HornetQ-client-global-threads-141278138)) Aggressively releasing JDBC connection
23:06:54,656 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== SCANNING
23:06:54,656 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread scanning
23:06:54,657 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery first pass at Tue, 17 Mar 2015 23:06:54
23:06:54,657 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule first pass
23:06:54,657 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions
23:06:54,657 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
23:06:54,657 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - first pass
23:06:54,659 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
23:06:54,659 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - first pass
23:06:54,660 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) Recovery user name=sa
23:06:54,660 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) Recovery Subject=Subject:
    Principal: sa
    Private Credential: javax.resource.spi.security.PasswordCredential@35c11c

23:06:54,660 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) Open managed connection (Subject:
    Principal: sa
    Private Credential: javax.resource.spi.security.PasswordCredential@35c11c
)
23:06:54,660 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) Open connection (org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@12baccec, Subject:
    Principal: sa
    Private Credential: javax.resource.spi.security.PasswordCredential@35c11c
)
23:06:54,661 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) Closing connection for recovery check (org.jboss.jca.adapters.jdbc.jdk7.WrappedConnectionJDK7@6cb68463)
23:06:54,661 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) Force close=false
23:06:54,661 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) Recovery XAResource=XAResourceWrapperImpl@42adb757[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@12baccec pad=false overrideRmValue=false productName=H2 productVersion=1.3.173 (2013-07-28) jndiName=java:jboss/datasources/JTACrashRecQuickstartDS] for java:jboss/datasources/JTACrashRecQuickstartDS
23:06:54,662 DEBUG [org.hornetq.jms.server] (Periodic Recovery) 
=======================================================================================
23:06:54,662 DEBUG [org.hornetq.jms.server] (Periodic Recovery) Returning the following list on getXAREsources:
23:06:54,662 DEBUG [org.hornetq.jms.server] (Periodic Recovery) server-id=3f93832c-cce0-11e4-85a9-c34d99e66ea7, value=HornetQXAResourceWrapper [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], csf=ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], delegate=DelegatingSession [session=ClientSessionImpl [name=14033f14-cced-11e4-a9c4-0776b366296e, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=()]@25a3d1], xaRecoveryConfigs=[XARecoveryConfig [transportConfiguration = [TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryConfiguration = null, username=null, password=****]], instance=442315688]
23:06:54,662 DEBUG [org.hornetq.jms.server] (Periodic Recovery) =======================================================================================

23:06:54,663 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@1a5c141b, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@2f46ac03}, transactionOriginNodeIdentifier='1'}
23:06:54,663 DEBUG [org.jboss.ejb.client.txn] (Periodic Recovery) Send recover request for transaction origin node identifier 1 to EJB receiver with node name localhost
23:06:54,663 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 0 xids in doubt
23:06:54,663 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of XAResourceWrapperImpl@42adb757[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@12baccec pad=false overrideRmValue=false productName=H2 productVersion=1.3.173 (2013-07-28) jndiName=java:jboss/datasources/JTACrashRecQuickstartDS]
23:06:54,664 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 0 xids in doubt
23:06:54,664 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of HornetQXAResourceWrapper [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], csf=ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], delegate=DelegatingSession [session=ClientSessionImpl [name=14033f14-cced-11e4-a9c4-0776b366296e, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=()]@25a3d1], xaRecoveryConfigs=[XARecoveryConfig [transportConfiguration = [TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryConfiguration = null, username=null, password=****]], instance=442315688]
23:06:54,664 DEBUG [org.hornetq.jms.server] (Periodic Recovery) looking for recover at DelegatingSession [session=ClientSessionImpl [name=14033f14-cced-11e4-a9c4-0776b366296e, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=()]@25a3d1] configuration [XARecoveryConfig [transportConfiguration = [TransportConfiguration(name=c9103c7d-ccec-11e4-a9c4-0776b366296e, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryConfiguration = null, username=null, password=****]]
23:06:54,665 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 0 xids in doubt
23:06:54,665 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)
Debug at TRACE level Start of transaction 
2015-03-17 22:48:00,132 TRACE [org.xnio.listener] (default I/O-2) Invoking listener io.undertow.server.protocol.http.HttpOpenListener@7c41cb4e on channel org.xnio.nio.NioSocketStreamConnection@3512c7d3
2015-03-17 22:48:00,132 TRACE [io.undertow.request] (default I/O-2) Opened connection with /127.0.0.1:47595
2015-03-17 22:48:00,133 TRACE [org.xnio.nio.selector] (default I/O-2) Beginning select on sun.nio.ch.EPollSelectorImpl@6e222594
2015-03-17 22:48:00,133 TRACE [org.jboss.weld.Servlet] (default task-6) WELD-000708: Initializing request io.undertow.servlet.spec.HttpServletRequestImpl@3b1c643e
2015-03-17 22:48:00,134 TRACE [org.jboss.weld.Context] (default task-6) WELD-000222: Loading bean store org.jboss.weld.context.beanstore.http.LazySessionBeanStore@44f940c3 map from session null
2015-03-17 22:48:00,134 TRACE [org.jboss.weld.Bean] (default task-6) WELD-001545: MethodHandler processing call to public abstract void javax.transaction.UserTransaction.begin() throws javax.transaction.NotSupportedException,javax.transaction.SystemException for class org.jboss.weldx.transaction.UserTransaction$942642665$Proxy$_$$_Weld$Proxy$
2015-03-17 22:48:00,134 TRACE [com.arjuna.ats.jta] (default task-6) BaseTransaction.begin
2015-03-17 22:48:00,135 TRACE [com.arjuna.ats.arjuna] (default task-6) StateManager::StateManager( 2, 0 )
2015-03-17 22:48:00,135 TRACE [com.arjuna.ats.arjuna] (default task-6) BasicAction::BasicAction()
2015-03-17 22:48:00,135 TRACE [com.arjuna.ats.arjuna] (default task-6) BasicAction::Begin() for action-id 0:ffff7f000001:-520944e9:55089cdc:a6
2015-03-17 22:48:00,135 TRACE [com.arjuna.ats.arjuna] (default task-6) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-520944e9:55089cdc:a6
2015-03-17 22:48:00,135 TRACE [com.arjuna.ats.arjuna] (default task-6) ActionHierarchy::ActionHierarchy(1)
2015-03-17 22:48:00,135 TRACE [com.arjuna.ats.arjuna] (default task-6) ActionHierarchy::add(0:ffff7f000001:-520944e9:55089cdc:a6, 1)
2015-03-17 22:48:00,135 TRACE [com.arjuna.ats.arjuna] (default task-6) BasicAction::addChildThread () action 0:ffff7f000001:-520944e9:55089cdc:a6 adding Thread[default task-6,5,main]
2015-03-17 22:48:00,135 TRACE [com.arjuna.ats.arjuna] (default task-6) BasicAction::addChildThread () action 0:ffff7f000001:-520944e9:55089cdc:a6 adding Thread[default task-6,5,main] result = true
Start of Hibernate transaction 
2015-03-17 22:48:00,137 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,137 TRACE [com.arjuna.ats.jta] (default task-6) TransactionSynchronizationRegistryImple.registerInterposedSynchronization
2015-03-17 22:48:00,137 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,137 DEBUG [org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl] (default task-6) successfully registered Synchronization
2015-03-17 22:48:00,137 DEBUG [org.hibernate.jpa.spi.AbstractEntityManagerImpl] (default task-6) Looking for a JTA transaction to join
2015-03-17 22:48:00,137 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,137 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,137 TRACE [org.hibernate.internal.SessionImpl] (default task-6) Setting flush mode to: AUTO
2015-03-17 22:48:00,138 TRACE [org.hibernate.internal.SessionImpl] (default task-6) Setting cache mode to: NORMAL
2015-03-17 22:48:00,138 DEBUG [org.jboss.as.jpa] (default task-6) default task-6:transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: created entity manager session TransactionImple < ac, BasicAction: 0:ffff7f000001:-520944e9:55089cdc:a6 status: ActionStatus.RUNNING >
2015-03-17 22:48:00,138 TRACE [com.arjuna.ats.jta] (default task-6) TransactionSynchronizationRegistryImple.registerInterposedSynchronization
2015-03-17 22:48:00,138 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,138 TRACE [com.arjuna.ats.jta] (default task-6) TransactionSynchronizationRegistryImple.putResource
2015-03-17 22:48:00,138 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,138 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,138 TRACE [com.arjuna.ats.jta] (default task-6) TransactionSynchronizationRegistryImple.getResource
2015-03-17 22:48:00,138 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,138 DEBUG [org.jboss.as.jpa] (default task-6) default task-6:transaction scoped EntityManager [wildfly-jta-crash-rec.war#primary]: reuse entity manager session already in tx TransactionImple < ac, BasicAction: 0:ffff7f000001:-520944e9:55089cdc:a6 status: ActionStatus.RUNNING >
2015-03-17 22:48:00,139 TRACE [org.hibernate.internal.SessionImpl] (default task-6) Setting cache mode to: NORMAL
2015-03-17 22:48:00,139 TRACE [org.hibernate.event.internal.DefaultLoadEventListener] (default task-6) Loading entity: [org.jboss.as.quickstarts.xa.KVPair#k15]
Register resources into transaction 
2015-03-17 22:48:00,142 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,143 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.enlistResource ( XAResourceWrapperImpl@2da65345[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@2a4ee6d pad=false overrideRmValue=false productName=H2 productVersion=1.3.173 (2013-07-28) jndiName=java:jboss/datasources/JTACrashRecQuickstartDS] )
2015-03-17 22:48:00,143 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,143 TRACE [com.arjuna.ats.arjuna] (default task-6) StateManager::StateManager( 1, 0 )
2015-03-17 22:48:00,143 TRACE [com.arjuna.ats.arjuna] (default task-6) AbstractRecord::AbstractRecord (0:ffff7f000001:-520944e9:55089cdc:ab, 1)
2015-03-17 22:48:00,143 TRACE [com.arjuna.ats.jta] (default task-6) XAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-520944e9:55089cdc:a6, node_name=1, branch_uid=0:ffff7f000001:-520944e9:55089cdc:aa, subordinatenodename=null, eis_name=java:jboss/datasources/JTACrashRecQuickstartDS >, XAResourceWrapperImpl@2da65345[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@2a4ee6d pad=false overrideRmValue=false productName=H2 productVersion=1.3.173 (2013-07-28) jndiName=java:jboss/datasources/JTACrashRecQuickstartDS] ), record id=0:ffff7f000001:-520944e9:55089cdc:ab
2015-03-17 22:48:00,143 TRACE [com.arjuna.ats.arjuna] (default task-6) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:-520944e9:55089cdc:ab
2015-03-17 22:48:00,143 DEBUG [org.hibernate.engine.jdbc.internal.LogicalConnectionImpl] (default task-6) Obtained JDBC connection
2015-03-17 22:48:00,144 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,144 TRACE [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-6) Registering statement [org.jboss.jca.adapters.jdbc.jdk7.WrappedPreparedStatementJDK7@176f445a]
2015-03-17 22:48:00,144 TRACE [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-6) Registering last query statement [org.jboss.jca.adapters.jdbc.jdk7.WrappedPreparedStatementJDK7@176f445a]
2015-03-17 22:48:00,144 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] (default task-6) binding parameter [1] as [VARCHAR] - [k15]
2015-03-17 22:48:00,144 TRACE [org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader] (default task-6) Bound [2] parameters total
2015-03-17 22:48:00,169 TRACE [com.arjuna.ats.jta] (default task-6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2015-03-17 22:48:00,169 TRACE [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-6) Registering result set [rs43: org.h2.result.LocalResult@4d487c46 columns: 2 rows: 0 pos: -1]
2015-03-17 22:48:00,169 TRACE [org.hibernate.loader.plan.exec.process.internal.ResultSetProcessorImpl] (default task-6) Processing result set
Transaction commit 
2015-03-17 22:48:00,269 TRACE [com.arjuna.ats.arjuna] (default task-6) BasicAction::phase2Commit() for action-id 0:ffff7f000001:-520944e9:55089cdc:a6
2015-03-17 22:48:00,270 TRACE [com.arjuna.ats.arjuna] (default task-6) BasicAction::doCommit (XAResourceRecord < resource:XAResourceWrapperImpl@2da65345[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@2a4ee6d pad=false overrideRmValue=false productName=H2 productVersion=1.3.173 (2013-07-28) jndiName=java:jboss/datasources/JTACrashRecQuickstartDS], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-520944e9:55089cdc:a6, node_name=1, branch_uid=0:ffff7f000001:-520944e9:55089cdc:aa, subordinatenodename=null, eis_name=java:jboss/datasources/JTACrashRecQuickstartDS >, heuristic: TwoPhaseOutcome.FINISH_OK, product: H2/1.3.173 (2013-07-28), jndiName: java:jboss/datasources/JTACrashRecQuickstartDS com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@c3e0df8 >)
2015-03-17 22:48:00,270 TRACE [com.arjuna.ats.jta] (default task-6) XAResourceRecord.topLevelCommit for XAResourceRecord < resource:XAResourceWrapperImpl@2da65345[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@2a4ee6d pad=false overrideRmValue=false productName=H2 productVersion=1.3.173 (2013-07-28) jndiName=java:jboss/datasources/JTACrashRecQuickstartDS], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-520944e9:55089cdc:a6, node_name=1, branch_uid=0:ffff7f000001:-520944e9:55089cdc:aa, subordinatenodename=null, eis_name=java:jboss/datasources/JTACrashRecQuickstartDS >, heuristic: TwoPhaseOutcome.FINISH_OK, product: H2/1.3.173 (2013-07-28), jndiName: java:jboss/datasources/JTACrashRecQuickstartDS com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@c3e0df8 >, record id=0:ffff7f000001:-520944e9:55089cdc:ab
2015-03-17 22:48:00,270 TRACE [com.arjuna.ats.arjuna] (default task-6) BasicAction::doCommit() result for action-id (0:ffff7f000001:-520944e9:55089cdc:a6) on record id: (0:ffff7f000001:-520944e9:55089cdc:ab) is (TwoPhaseOutcome.FINISH_OK) node id: (1)
2015-03-17 22:48:00,271 TRACE [com.arjuna.ats.arjuna] (default task-6) BasicAction::doCommit (XAResourceRecord < resource:XAResourceWrapperImpl@36398b1e[xaResource=org.hornetq.ra.HornetQRAXAResource@403647b1 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-520944e9:55089cdc:a6, node_name=1, branch_uid=0:ffff7f000001:-520944e9:55089cdc:ad, subordinatenodename=null, eis_name=java:/JmsXA >, heuristic: TwoPhaseOutcome.FINISH_OK, product: HornetQ/2.0, jndiName: java:/JmsXA com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@3e071b0f >)
2015-03-17 22:48:00,271 TRACE [com.arjuna.ats.jta] (default task-6) XAResourceRecord.topLevelCommit for XAResourceRecord < resource:XAResourceWrapperImpl@36398b1e[xaResource=org.hornetq.ra.HornetQRAXAResource@403647b1 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-520944e9:55089cdc:a6, node_name=1, branch_uid=0:ffff7f000001:-520944e9:55089cdc:ad, subordinatenodename=null, eis_name=java:/JmsXA >, heuristic: TwoPhaseOutcome.FINISH_OK, product: HornetQ/2.0, jndiName: java:/JmsXA com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@3e071b0f >, record id=0:ffff7f000001:-520944e9:55089cdc:ae
2015-03-17 22:48:00,271 TRACE [org.hornetq.ra] (default task-6) commit(< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-520944e9:55089cdc:a6, node_name=1, branch_uid=0:ffff7f000001:-520944e9:55089cdc:ad, subordinatenodename=null, eis_name=java:/JmsXA >, false)
Posted by at No comments:
Labels: , ,

Wednesday, July 10, 2013

Weblogic 12c - tune and debug JMS OAQ module

Interoperating with Oracle AQ JMS

 http://docs.oracle.com/cd/E24329_01/web.1211/e24385/aq_jms.htm

To use AQ JMS tracing and debugging, set the following system property: oracle.jms.traceLevel

Parameters for tuning:

max-threads-constraint - Work Manager- this should be higher than min-threads-constraint http://docs.oracle.com/cd/E24329_01/web.1211/e24432/self_tuned.htm#i1068070

min-threads-constraint - Work Manager

max-beans-in-free-pool - weblogic-ejb-jar.xml - http://docs.oracle.com/cd/E24329_01/web.1211/e24973/ejb_jar_ref.htm#autoId167

WebLogic Server maintains a free pool of EJBs for every entity bean, stateless session bean, and message-driven bean class. The max-beans-in-free-pool element defines the size of this pool.

Determining the Number of Concurrent MDBs

 http://docs.oracle.com/cd/E24329_01/web.1211/e24390/mdbtuning.htm#i1134848

Custom work manager with constraint
varies due to self-tuning, between min-thread-constraint and Min(max-threads-constraint, max-beans-in-free-pool)

You can reserve threads by  specifying a work manager with a min-threads-constraint

 

Thread dump analysis

http://allthingsmdw.blogspot.cz/2012/02/analyzing-thread-dumps-in-middleware_08.html 

Posted by at No comments:
Labels: , ,

Thursday, February 4, 2010

Weblogic server and Oracle AQ JMS

Interoperating with Oracle AQ JMS
http://download.oracle.com/docs/cd/E15523_01/web.1111/e13738/aq_jms.htm#CJACBCEJ

Configure a JMS Foreign Server
http://download.oracle.com/docs/cd/E15523_01/web.1111/e13738/aq_jms.htm#CJACJIAE
Posted by at No comments:
Labels: , ,

Thursday, November 12, 2009

Using run-as-principal in MDB deployment descriptor

ejb-jar.xml
            <security-identity>
                <run-as>
                 <role-name>Admin</role-name>
                 </run-as>
                </security-identity>
        </message-driven>


...
<assembly-descriptor>
    <security-role>
         <role-name>Admin</role-name>
    </security-role>
        <container-transaction>


weblogic-ejb-jar.xml
<security-role-assignment>
            <role-name>
                    Admin
            </role-name>
                <principal-name>
                weblogic
                </principal-name>
          </security-role-assignment>
          <run-as-role-assignment>
        <role-name> 
            Admin 
        </role-name>
        <run-as-principal-name>
            weblogic
        </run-as-principal-name>
    </run-as-role-assignment>
Posted by at No comments:
Labels: , , ,

Wednesday, July 1, 2009

MDB 3. 0 on Weblogic 10.3 using Oracle AQ ( Advanced Queue) 



package testEAR;

import javax.ejb.ActivationConfigProperty;
import javax.ejb.MessageDriven;
import javax.jms.JMSException;
import javax.jms.Message;
import javax.jms.MessageListener;
import javax.jms.TextMessage;

import weblogic.javaee.MessageDestinationConfiguration;

@MessageDestinationConfiguration(connectionFactoryJNDIName = "jms.aq.AQFactory")
@MessageDriven(
        activationConfig = { 
                @ActivationConfigProperty(propertyName = "destinationType",
                        propertyValue = "javax.jms.Queue") },
                        mappedName = "jms.aq.MY_QUEUE"
            )
public class TestMDB implements MessageListener {

    public void onMessage(Message message) {
        TextMessage txtMsg = null;

        txtMsg = (TextMessage) message;
        try {
            String stringMessage = txtMsg.getText();

            System.out.print("Payload: " + stringMessage + "\n");

        } catch (JMSException e) {
            e.printStackTrace();
        }
    }
}
Posted by at No comments:
Labels: , , ,
Subscribe to: Comments (Atom)