Where are JBoss logs located?

We will shortly discuss where JBoss EAP / WildFly logs are located. The location of JBoss logs basically depends on which mode you are using to start the application server.

View logs in standalone mode

When running in standalone mode, JBoss logs are located in the standalone/log folder:

standalone
├── configuration
├── data
├── deployments
├── lib
│   └── ext
├── log
│   ├── audit.log
│   ├── server.log
│   └── server.log.2021-08-15
└── tmp

As you can see, the currently running server has created the server.log file.

Therefore, to view logs it is sufficient to tail that file:

tail -f $JBOSS_HOME/standalone/logs/server.log

By default, JBoss / WildFly configuration uses a Periodic Rotating Logger which rotates logs on a time basis (by default daily):

<periodic-rotating-file-handler name="FILE" autoflush="true">
    <formatter>
        <named-formatter name="PATTERN"/>
    </formatter>
    <file relative-to="jboss.server.log.dir" path="server.log"/>
    <suffix value=".yyyy-MM-dd"/>
    <append value="true"/>
</periodic-rotating-file-handler>

View logs in Domain mode

When running in Domain mode, JBoss logs you will find log files at two different levels:

.
├── configuration
├── data
├── log
│   ├── audit.log
│   ├── host-controller.log
│   └── process-controller.log
├── servers
│   ├── server-one
│   │   ├── data
│   │   ├── log
│   │   │   ├── audit.log
│   │   │   └── server.log
│   │   └── tmp
│   └── server-two
│       ├── data
│       ├── log
│       │   ├── audit.log
│       │   └── server.log
│       └── tmp
└── tmp

  • Within the domain/log folder: this folder contains the log files of the Host Controller. Please note that the Host Controller is used to manage the Domain of JBoss/WildFly servers. It does not contain application log file
  • Within the domain/servers/server-name/log folder: this folder contains the server log files for the “server-name”. Applications which are deployed on that server will output their logs there.

Finally, please note that the above coordinates are the default ones where JBoss prints log files. You can write your logs to another location (f.e. on a different partition) by configuring the path attribute of your Logging Handler:

 <file  path="/extfs/logs/server.log"/>

Configuring a JBoss Handler which writes in a distinct file logs for a package

This article shows how to configure a JBoss Logging Handler for a specific package (category) to be written in a separate log file.

Sometimes you need to add verbosity to a specific JBoss/WildFly package but you don’t want to mix it with the application server’s logs. So, in order to do that, you need to perform the following steps:

  • Define a Handler which points to a file path. In most cases, the Periodic Rotating File Handler is the best choice
  • Define a Logger, which contains the package (“category”) to be traced and the level of verbosity
<periodic-rotating-file-handler name="JTA-LOG" autoflush="true">
            <file relative-to="jboss.server.log.dir" path="${jboss.node.name}_jta.log"/>
            <rotate-size value="20000"/>
            <max-backup-index value="3"/>
            <suffix value=".yyyy-MM-dd"/>
            <suffix value=".yyyy-MM-dd"/>
            <append value="true"/>
</periodic-rotating-file-handler>
 
<logger category="com.arjuna.ats.jta" use-parent-handlers="false">
        <level name="TRACE"/>
        <handlers>
                <handler name="JTA-LOG"/>
        </handlers>
</logger>

<root-logger>
        <level name="INFO"/>
        <handlers>
            <handler name="JTA-LOG"/>
            <handler name="CONSOLE"/>
            <handler name="FILE"/>           
        </handlers>
</root-logger>

In this example configuration, we have defined a Perodic Rotating File Handler writing a file named ${jboss.node.name}_jta.log in the standard log dir. This Handler traces the package “com.arjuna.ats.jta” and it is added to the roo-logger. This will help you to keep the logs for a specific package in a separate log file.

How to use Log4j2 in your WildFly applications

Log4j2 is the latest major release of the popular Logging Framework. In this tutorial we will learn how to include Log4j2 configuration file and use it in your deployments running on WildFly.

Log4j2 borrows some concepts from the Logback framework, which can be assimilated to an improved version of the older Log4j release. According to the official document of Apache Log4j 2 the major highlights of this release are:

  • The Log4j 2 API is a logging facade that may be used with the Log4j 2 implementation, but may also be used in front of other logging implementations such as Logback.
  • Improved performance: In multi-threaded scenarios the Asynchronous Loggers have a fairly higher throughput than Log4j and Logback.
  • Support for multiple APIs: Log4j 2 provides support for Log4j 1.2, SLF4J, Commons Logging and java.util.logging (JUL) APIs.
  • Automatic reloading of configurations: Log4j 2 can automatically reload its configuration upon modification.
  • Advanced filtering: Log4j 2 supports filtering based on context data, markers, regular expressions, and other components in the Log event.
  • Java 8 Lambda support
  • Custom log levels:Log4J 2 supports custom log levels. Custom log levels can be defined in code or in configuration.
  • Low Garbage collector impact: Garbage-free logging in Log4j is partially implemented by reusing objects in ThreadLocal fields, and partially by reusing buffers when converting text to bytes.

That being said, let’s see how to implement Log4j2 in WildFly application server.

Within WildFly modules, there is a facade from log4j to JBoss Log Manager:

$ tree log4j
log4j/
└── logmanager
    └── main
        ├── log4j-jboss-logmanager-1.2.0.Final.jar
        └── module.xml

In order to delegate logging to log4j2 there are some steps to be completed. First, we must configure the “per-deployment logging” strategy.  As a matter of fact, per-deployment-logging will search the WildFly ClassLoader for one of the logging provider implementations using a predefined order:

  • WildFLy LogManager
  • Log4j
  • Slf4j
  • JDK logging

If both WildFly LogManager and Log4j2 are found in the classpath then WildFly LogManager will be used because it has the “higher precedence”. We can set to false the use-deployment-logging-config as follows, from the CLI:

/subsystem=logging:write-attribute(name=use-deployment-logging-config,value=false)

Next, let’s create a sample log4j2.xml file which includes a Rolling Appender with both the time and size based triggering policies.

<Configuration status="warn" name="MyApp" packages="">
      <Appenders>
        <RollingFile name="RollingFile" fileName="${env:JBOSS_HOME}/standalone/log/application.log"
                     filePattern="${env:JBOSS_HOME}/standalone/log/${date:yyyy-MM}/app-%d{MM-dd-yyyy}-%i.log.gz">
          <PatternLayout>
            <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
          </PatternLayout>
          <Policies>
            <TimeBasedTriggeringPolicy />
            <SizeBasedTriggeringPolicy size="100 MB"/>
          </Policies>
        </RollingFile>
      </Appenders>
      <Loggers>
        <Root level="info">
          <AppenderRef ref="RollingFile"/>
        </Root>
      </Loggers>
 </Configuration> 

The above log4j2.xml file will create up to 7 archives on the same day (1-7) to be stored in $JBOSS_HOME directory based on the current year and month, and will compress each archive using gzip.

Let’s copy the log4j2.xml file into the $JBOSS_HOME/standalone/configuration:

cp log4j2.xml $JBOSS_HOME/standalone/configuration

Now we will instruct WildFly to pickup log4j configuration file in its “standalone/configuration” folder:

 /system-property=log4j.configurationFile:add(value=${env.JBOSS_HOME}/standalone/configuration/log4j2.xml)

We are done with WildFly configuration. Now let’s create a sample demo application which uses log4j2 from WildFly. The source code for this application is available at: https://github.com/fmarchioni/mastertheboss/tree/master/log/log4j2

As you can see, in the resources folder we have included a jboss-deployment-structure.xml which excludes the default org.apache.log4j and org.apache.commons.logging modules available in WildFly:

<jboss-deployment-structure xmlns="urn:jboss:deployment-structure:1.2">
    <deployment>
        <exclusions>
            <module name="org.apache.log4j" />
            <module name="org.apache.commons.logging"/>
        </exclusions>
    </deployment>
</jboss-deployment-structure>
Please bear in mind that, for EAR deployments, you need to exclude the above packages from your deployment and all subdeployments. That means to specify the exclusion in the jboss-deployment-structure.xml at the EAR level, and then inside each WAR/JAR nested deployment.

Within our application, the following Servlet will use Log4j2 to output some logs:

@WebServlet(name = "hello", urlPatterns = { "/hello" })
public class HelloWorldServlet extends HttpServlet {


  Logger logger = LogManager.getLogger(HelloWorldServlet.class);

  public HelloWorldServlet() {
    super();

  }
  
  protected void doGet(HttpServletRequest request,
            HttpServletResponse response) throws ServletException, IOException {

    response.setContentType("text/html");
    PrintWriter writer = response.getWriter();
    writer.println("<h1>Hello World Servlet on WildFly</h1>");
    logger.info("Hello world Log4j2 on WildFly");
    logger.info("Request URI {} - Session Id {}.", request.getRequestURI(), request.getSession().getId());

    writer.close();
    }
    
  protected void doPost(HttpServletRequest request,
      HttpServletResponse response) throws ServletException, IOException {
    doGet(request, response);
  }

}

Please notice we are using a sample of parameterized logging. This mechanism, introduced by SLF4J, uses ‘{}’ to indicate where placeholders occur and which are the String values uses to replace the parameters.

To be able to build and deploy the application, you will need to add the log4j api and core in your pom.xml file:

    <dependency>
      <groupId>org.apache.logging.log4j</groupId>
      <artifactId>log4j-api</artifactId>
      <version>2.13.3</version>
    </dependency>

    <dependency>
      <groupId>org.apache.logging.log4j</groupId>
      <artifactId>log4j-core</artifactId>
      <version>2.13.3</version>
    </dependency>

If using Gradle, the equivalent configuration is:

compile group: 'org.apache.logging.log4j', name: 'log4j-api', version: '2.13.3'
compile group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.13.3'

That’s it. Now deploy the application and invoke the example Servlet. You should see that the “application.log” has been created in the $JBOSS_HOME/standalone/log with some content in it:

2020-08-16 12:52:12,093 INFO c.m.s.HelloWorldServlet [default task-1] Hello world Log4j2 on WildFly
2020-08-16 12:52:12,100 INFO c.m.s.HelloWorldServlet [default task-1] Request URI /log4jdemo/hello - Session Id Xr1roaugFzX-mVE0rrDCZWqN09XiVqJRrT8Ca6r_.

Keeping your Log4j libs in sync

If you are using multiple libraries under the log4j2 umbrella, it is recommended to include a Bill of Material to keep them in synch:

<dependencyManagement>
	<dependencies>
		<dependency>
			<groupId>org.apache.logging.log4j</groupId>
			<artifactId>log4j-bom</artifactId>
			<version>2.13.3</version>
			<scope>import</scope>
			<type>pom</type>
		</dependency>
	</dependencies>
</dependencyManagement>

With that in place, it is not required to specify the version of the single Log4j artifacts:

<dependency>
	<groupId>org.apache.logging.log4j</groupId>
	<artifactId>log4j-api</artifactId>
</dependency>
<dependency>
	<groupId>org.apache.logging.log4j</groupId>
	<artifactId>log4j-core</artifactId>
</dependency>

Using an Async Log4j Logger

There are several Loggers available with Log4j. Here we will just show an example of a basic Async appender. Check the documentation at: https://logging.apache.org/log4j/2.0/manual/appenders.html#AsyncAppender to learn how to customize this appender:

<Configuration status="warn" name="MyApp" packages="">
  <Appenders>
    <File name="MyFile" fileName="${env:JBOSS_HOME}/standalone/log/async_application.log">
      <PatternLayout>
        <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
      </PatternLayout>
    </File>
    <Async name="Async">
      <AppenderRef ref="MyFile"/>
    </Async>
  </Appenders>
  <Loggers>
    <Root level="info">
      <AppenderRef ref="Async"/>
    </Root>
  </Loggers>
</Configuration>

References: https://logging.apache.org/log4j/2.0/index.html

How to configure log4j in your ear ?

This article is now obsolete. We recommend checking these resources to learn bout log4j configuration with JBoss / WildFly:


Have you got exceptions when tried to configure log4j at application level ? this is due to the fact that JBoss ships already with log4j classes:  you need to isolate the classes from other deployments. Without isolation, you can see common errors like ClassCastException, IllegalAccessErrors, VerifyErrors and in general, strange behavior.

Here’s how to do it:
Create a log4j.properties file and package it with your application and make it visible to JBoss classpath (see image at the bottom). The log4j.properties has just a minimal content: 

log4j.logger.com.sample=TRACE

Within your application you need to add the appropriate version of log4j jar (this is important  because you will have to ensure that log4j initializes separately for your application and picks up the log4j.properties file). Place this log4j jar file in the lib folder of your EAR (as depicted in the picture).

Finally you need to  enable classloader isolation for your application. In order to achieve classloader isolation you need to add an entry in jboss-app.xml file and place it in the META-INF folder of the EAR. The jboss-app.xml looks like:

<jboss-app>
  <loader-repository>
 org.myapp:loader=MyClassLoader
     <loader-repository-config>java2ParentDelegation=false </loader-repository-config>
   </loader-repository>
 </jboss-app>

This is how your application EAR should look like:

Create a Custom Camel logging handler for WildFly

A Custom logging handler allows you to define a custom destination for your WildFly / JBoss AS 7 server logging events. You would typically define a custom hanlder to log to a Socket, a Database, to a remote location or a JMS Queue. In this tutorial we will learn how to base your custom handler on a Camel route so that you might choose any possible route for your logs!

The first step for creating a custom handler is extending the java.util.logging.Handler, implementing its mandatory methods.

Here’s the skeleton of our CamelHandler:

package com.mastertheboss.camel.handler;

import java.util.logging.Handler;
import java.util.logging.LogRecord;
import org.apache.camel.CamelContext;
import org.apache.camel.builder.RouteBuilder;
import org.apache.camel.impl.DefaultCamelContext;

import org.apache.camel.ProducerTemplate;

public class CamelHandler extends Handler {

	//Publish a LogRecord.
	public void publish(LogRecord record) {
	}

	//Flush any buffered output.
	public void flush() {
	}

	//Close the Handler and free all associated resources.
	public void close() throws SecurityException {
	}

}

Within it, we will add a class variable for storing the destination of your Camel route, an init() method for creating the org.apache.camel.CamelContext and the org.apache.camel.ProducerTemplate. The publish method will send the LogRecord to the Camel’s direct component. Here’s the full version of our CamelHandler:

package com.mastertheboss.camel.handler;

import java.util.logging.Handler;
import java.util.logging.LogRecord;
import org.apache.camel.CamelContext;
import org.apache.camel.builder.RouteBuilder;
import org.apache.camel.impl.DefaultCamelContext;

import org.apache.camel.ProducerTemplate;

public class CamelHandler extends Handler {
	CamelContext context;
	ProducerTemplate template;

	// Set on WildFly
	private String destination;

	public String getDestination() {
		return destination;
	}

	public void setDestination(String destination) {
		this.destination = destination;
		init();
	}

	private void init() {

		context = new DefaultCamelContext();
		try {
			context.addRoutes(new RouteBuilder() {
				public void configure() {
					from("direct:logger").to(destination);
				}
			});
			context.start();
		} catch (Exception e) {

			e.printStackTrace();
		}

		template = context.createProducerTemplate();
	}



	@Override
	public void publish(LogRecord record) {

		template.sendBody("direct:logger", record.getMessage());

	}

	@Override
	public void flush() {
		// TODO Auto-generated method stub

	}

	@Override
	public void close() throws SecurityException {
		try {
			template.stop();
			context.stop();
		} catch (Exception e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		}

	}

}

You need to package this class in a JAR and install it as a module. Your module will include as well the camel-core library and any component’s library that is used by the route. For keep it simple, we will start using a File route which is a built-in component, so we will just need the camel-core-2.18.2.jar.

module add --name=com.camelhandler --resource-delimiter=, --resources=camel-handler.jar,camel-core-2.18.2.jar --dependencies=org.slf4j,javax.xml.bind.api,javax.api,sun.jdk

And here’s the module.xml file created:

<module xmlns="urn:jboss:module:1.1" name="com.camelhandler">

    <resources>
        <resource-root path="camel-handler.jar"/>
        <resource-root path="camel-core-2.18.2.jar"/>
    </resources>

    <dependencies>
        <module name="org.slf4j"/>
        <module name="javax.xml.bind.api"/>
        <module name="javax.api"/>
        <module name="sun.jdk"/>
    </dependencies>
</module>

Great, now let’s define a custom handler on the application server which used this module:

<custom-handler name="CamelHandler" class="com.mastertheboss.camel.handler.CamelHandler" module="com.camelhandler">  
	<properties>
	 	<property name="destination" value="file:/var/log/camel?fileName=server.log" />
	</properties>
	<level name="INFO"/>  
	<formatter>  
	    <pattern-formatter pattern="%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%E%n"/>  
	</formatter>  
</custom-handler>

Now either define a Logger for a specific package or, to have a quick try, include this handler in the root logger:

<root-logger>
        <level name="INFO"/>
        <handlers>
            <handler name="CamelHandler"/>
            <handler name="CONSOLE"/>
            <handler name="FILE"/>
        </handlers>
</root-logger>

We’re done! reload your server and check that the server log messages are being written also in the path defined in your “destination”.

Besides writing to a File, which is a Camel built-in component, you have an unlimited set of options for routing your log messages. For example, by providing an ActiveMQConnectionFactory to the CamelContext then you could push your log messages to an ActiveMQ server with small adjustments to your Handler:

package com.mastertheboss.camel.handler;

import java.util.logging.Handler;
import java.util.logging.LogRecord;
import org.apache.camel.CamelContext;
import org.apache.camel.builder.RouteBuilder;
import org.apache.camel.impl.DefaultCamelContext;

import org.apache.camel.ProducerTemplate;

import javax.jms.ConnectionFactory;
import org.apache.activemq.ActiveMQConnectionFactory;
import org.apache.camel.component.jms.JmsComponent;
 

public class CamelHandler extends Handler {
	CamelContext context;
	ProducerTemplate template;

	// Set on WildFly
	private String destination;

	private void init() {

		context = new DefaultCamelContext();
		ConnectionFactory connectionFactory = new ActiveMQConnectionFactory(
                "tcp://0.0.0.0:61616");
                context.addComponent("jms",
                JmsComponent.jmsComponentAutoAcknowledge(connectionFactory));
        
		try {
			context.addRoutes(new RouteBuilder() {
				public void configure() {
					from("direct:logger").to(destination);
				}
			});
			context.start();
		} catch (Exception e) {

			e.printStackTrace();
		}

		template = context.createProducerTemplate();
	}

	public String getDestination() {
		return destination;
	}

	public void setDestination(String destination) {
		this.destination = destination;
		init();
	}

	@Override
	public void publish(LogRecord record) {

		template.sendBody("direct:logger", record.getMessage());

	}

	@Override
	public void flush() {
		// TODO Auto-generated method stub

	}

	@Override
	public void close() throws SecurityException {
		try {
			template.stop();
			context.stop();
		} catch (Exception e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		}

	}

}

That would require some additional JARS to be placed in your module:

<module xmlns="urn:jboss:module:1.1" name="com.camelhandler">

    <resources>
        <resource-root path="camel-handler.jar"/>
        <resource-root path="camel-core-2.18.2.jar"/>
        <resource-root path="camel-jms-2.18.2.jar"/>
        <resource-root path="activemq-camel-5.13.4.jar" />
        <resource-root path="activemq-broker-5.13.4.jar" />
        <resource-root path="activemq-client-5.13.4.jar" />
        <resource-root path="activemq-pool-5.13.3.jar" />

    </resources>

    <dependencies>
        <module name="org.slf4j"/>
        <module name="javax.xml.bind.api"/>
        <module name="javax.api"/>
        <module name="sun.jdk"/>
    </dependencies>
</module>

Now you can choose as destination for your log an ActiveMQ queue, instead of a File:

<custom-handler name="CamelHandler" class="com.mastertheboss.camel.handler.CamelHandler" module="com.camelhandler">  
	<properties>
	 	<property name="destination" value="jms:queue:activemq/queue/ServerLogQueue" />
	</properties>
	<level name="INFO"/>  
	<formatter>  
	    <pattern-formatter pattern="%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%E%n"/>  
	</formatter>  
</custom-handler>

Enjoy logging with your Camel handler!

5 WildFly Loggers you should know about

in WildFly and JBoss EAP Loggers are used to log messages by defining a category generally consisting of a package name or a class name. In short, they can let you customize the logging events for a package or Class name. We will see 5 Loggers which I’ve found pretty useful in my work.

org.jboss.remoting.remote

<logger category="org.jboss.remoting.remote">
         <level name="TRACE"/>
</logger>

Cannot say how helpful is this logger! Handling remote EJB connections is not a walk in the park to be honest and the Exception “No EJB receiver available for handling” opens to different scenarios. By including this logger you can solve at least two common problems:

1) Probe that the application server received the incoming connection (Yes tcpdump is the best, but you have to be root in order to use it!)

Here is a sample log from a successful handled connection:

2016-04-15 22:47:38,710 TRACE [org.jboss.remoting.remote] (default I/O-5) Accepted connection from /127.0.0.1:36556 to localhost.localdomain/127.0.0.1:8080
2016-04-15 22:47:38,710 TRACE [org.jboss.remoting.remote] (default I/O-5) Setting read listener to org.jboss.remoting3.remote.ServerConnectionOpenListener$Initial@23d6ef6a
2016-04-15 22:47:38,710 TRACE [org.jboss.remoting.remote.connection] (default I/O-5) Can't directly send message java.nio.DirectByteBuffer[pos=0 lim=24 cap=8192], enqueued
2016-04-15 22:47:38,710 TRACE [org.jboss.remoting.remote.connection] (default I/O-5) Sent message java.nio.DirectByteBuffer[pos=24 lim=24 cap=8192] (via queue)
2016-04-15 22:47:38,710 TRACE [org.jboss.remoting.remote.connection] (default I/O-5) Flushed channel
2016-04-15 22:47:38,807 TRACE [org.jboss.remoting.remote.server] (default I/O-5) Server received capabilities request
2016-04-15 22:47:38,808 TRACE [org.jboss.remoting.remote.server] (default I/O-5) Server received capability: version 1
2016-04-15 22:47:38,808 TRACE [org.jboss.remoting.remote.server] (default I/O-5) Server received capability: remote endpoint name "config-based-ejb-client-endpoint"
2016-04-15 22:47:38,808 TRACE [org.jboss.remoting.remote.server] (default I/O-5) Server received capability: message close protocol supported
2016-04-15 22:47:38,808 TRACE [org.jboss.remoting.remote.server] (default I/O-5) Server received capability: remote version is "4.0.18.Final"
2016-04-15 22:47:38,808 TRACE [org.jboss.remoting.remote.server] (default I/O-5) Server received capability: remote channels in is "40"
2016-04-15 22:47:38,808 TRACE [org.jboss.remoting.remote.server] (default I/O-5) Server received capability: remote channels out is "40"
com.sun.security.sasl.ServerFactoryImpl@442be6bc
2016-04-15 22:47:38,809 TRACE [org.jboss.remoting.remote.server] (default I/O-5) Excluding mechanism CRAM-MD5 because it is not in the allowed list
2016-04-15 22:47:38,809 TRACE [org.jboss.remoting.remote.server] (default I/O-5) Trying SASL server factory com.sun.security.sasl.gsskerb.FactoryImpl@3ccb19f1
2016-04-15 22:47:38,809 TRACE [org.jboss.remoting.remote.server] (default I/O-5) Excluding mechanism GSSAPI because it is not in the allowed list
2016-04-15 22:47:38,809 TRACE [org.jboss.remoting.remote.connection] (default I/O-5) Can't directly send message java.nio.DirectByteBuffer[pos=0 lim=73 cap=8192], enqueued
2016-04-15 22:47:38,809 TRACE [org.jboss.remoting.remote.connection] (default I/O-5) Sent message java.nio.DirectByteBuffer[pos=73 lim=73 cap=8192] (via queue)
2016-04-15 22:47:38,809 TRACE [org.jboss.remoting.remote.connection] (default I/O-5) Flushed channel

2) More details on possible failures in communication:

Here is a sample log from a failed authentication due to a mistyped user in the jboss-ejb-client.properties:

2016-04-16 17:55:54,121 TRACE [org.jboss.remoting.remote.server] (default I/O-1) Received java.nio.DirectByteBuffer[pos=280 lim=8192 cap=8192]
2016-04-16 17:55:54,121 TRACE [org.jboss.remoting.remote.server] (default I/O-1) Server received authentication response
2016-04-16 17:55:54,124 TRACE [org.jboss.remoting.remote.server] (default task-33) Server sending authentication rejected: javax.security.sasl.SaslException: DIGEST-MD5: IO error acquiring password [Caused by org.jboss.as.domain.management.security.UserNotFoundException: WFLYDM0019: User 'ejbuserX' not found.]
    at org.jboss.sasl.digest.DigestMD5Server.validateClientResponse(DigestMD5Server.java:629)
    at org.jboss.sasl.digest.DigestMD5Server.evaluateResponse(DigestMD5Server.java:270)
    at org.xnio.sasl.SaslUtils.evaluateResponse(SaslUtils.java:245)
    at org.xnio.sasl.SaslUtils.evaluateResponse(SaslUtils.java:217)
    at org.jboss.remoting3.remote.ServerConnectionOpenListener$AuthStepRunnable.run(ServerConnectionOpenListener.java:490)
    at org.jboss.remoting3.EndpointImpl$TrackingExecutor$1.run(EndpointImpl.java:717)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.jboss.as.domain.management.security.UserNotFoundException: WFLYDM0019: User 'ejbuser222' not found.

org.apache.activemq

<logger category="org.apache.activemq">
         <level name="TRACE"/>
</logger>

As you can imagine, by tracing the Messaging broker core package you will have useful insights on what’s going in and which messages are consumed. Watch out! the package name has changed so update your configurations if you have used the former org.hornetq Logger.

Here is for example the org.apache.activemq in action when receiving a message:

016-04-16 09:10:32,741 TRACE [org.apache.activemq.artemis.core.server] (Thread-16 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=e809b634-03a0-11e6-b719-e1aab88f48c3-1827981914-366741840)) ServerSessionPacketHandler::handlePacket,PACKET(SessionBindingQueryMessage)[type=49, channelID=11, packetObject=SessionBindingQueryMessage]
2016-04-16 09:10:32,741 TRACE [org.apache.activemq.artemis.core.server] (Thread-16 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=e809b634-03a0-11e6-b719-e1aab88f48c3-1827981914-366741840)) ServerSessionPacketHandler::scheduling response::PACKET(SessionBindingQueryResponseMessage_V2)[type=-8, channelID=0, packetObject=SessionBindingQueryResponseMessage_V2]
2016-04-16 09:10:32,743 INFO  [stdout] (default task-50) Producer ActiveMQMessageProducer->org.apache.activemq.artemis.core.client.impl.ClientProducerImpl@710bcf75
2016-04-16 09:10:32,744 INFO  [stdout] (default task-50) Message blank msg
2016-04-16 09:10:32,744 TRACE [org.apache.activemq.artemis.core.server] (Thread-16 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=e809b634-03a0-11e6-b719-e1aab88f48c3-1827981914-366741840)) ServerSessionPacketHandler::handlePacket,PACKET(SessionRequestProducerCreditsMessage)[type=79, channelID=11, packetObject=SessionRequestProducerCreditsMessage]
2016-04-16 09:10:32,744 TRACE [org.apache.activemq.artemis.core.server] (Thread-16 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=e809b634-03a0-11e6-b719-e1aab88f48c3-1827981914-366741840)) ServerSessionPacketHandler::scheduling response::null
2016-04-16 09:10:32,744 TRACE [org.apache.activemq.artemis.core.server] (Thread-16 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=e809b634-03a0-11e6-b719-e1aab88f48c3-1827981914-366741840)) ServerSessionPacketHandler::handlePacket,PACKET(SessionSendMessage)[type=71, channelID=11, packetObject=SessionSendMessage,message=ServerMessage[messageID=0,durable=true,userID=4f106b49-03a2-11e6-b719-e1aab88f48c3,priority=4, bodySize=194, timestamp=Sat Apr 16 09:10:32 CEST 2016,expiration=0, durable=true, address=null,properties=TypedProperties[__AMQ_CID=fb3a5265-03a1-11e6-b719-e1aab88f48c3]]@1076914897]
2016-04-16 09:10:32,745 TRACE [org.apache.activemq.artemis.core.server] (Thread-16 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=e809b634-03a0-11e6-b719-e1aab88f48c3-1827981914-366741840)) Message after routed=ServerMessage[messageID=79,durable=true,userID=4f106b49-03a2-11e6-b719-e1aab88f48c3,priority=4, bodySize=194, timestamp=Sat Apr 16 09:10:32 CEST 2016,expiration=0, durable=true, address=jms.queue.exampleQueue,properties=TypedProperties[__AMQ_CID=fb3a5265-03a1-11e6-b719-e1aab88f48c3]]@1076914897
2016-04-16 09:10:32,745 TRACE [org.apache.activemq.artemis.core.server] (Thread-16 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=e809b634-03a0-11e6-b719-e1aab88f48c3-1827981914-366741840)) ServerSessionPacketHandler::scheduling response::PACKET(NullResponseMessage)[type=21, channelID=0, packetObject=NullResponseMessage]

And here is an MDB, consuming the above message:

2016-04-16 09:10:32,749 TRACE [org.apache.activemq.artemis.core.server] (Thread-23 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$2@7a10996c-1751602232)) ServerConsumerImpl::ServerConsumerImpl [id=0, filter=null, binding=LocalQueueBinding [address=jms.queue.exampleQueue, queue=QueueImpl[name=jms.queue.exampleQueue, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::serverUUID=e809b634-03a0-11e6-b719-e1aab88f48c3]]@200ce714, filter=null, name=jms.queue.exampleQueue, clusterName=jms.queue.exampleQueuee809b634-03a0-11e6-b719-e1aab88f48c3]] Handling reference Reference[79]:RELIABLE:ServerMessage[messageID=79,durable=true,userID=4f106b49-03a2-11e6-b719-e1aab88f48c3,priority=4, bodySize=256, timestamp=Sat Apr 16 09:10:32 CEST 2016,expiration=0, durable=true, address=jms.queue.exampleQueue,properties=TypedProperties[__AMQ_CID=fb3a5265-03a1-11e6-b719-e1aab88f48c3]]@1076914897
2016-04-16 09:10:32,750 TRACE [org.apache.activemq.artemis.core.server] (Thread-23 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$2@7a10996c-1751602232)) ServerConsumerImpl [id=0, filter=null, binding=LocalQueueBinding [address=jms.queue.exampleQueue, queue=QueueImpl[name=jms.queue.exampleQueue, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::serverUUID=e809b634-03a0-11e6-b719-e1aab88f48c3]]@200ce714, filter=null, name=jms.queue.exampleQueue, clusterName=jms.queue.exampleQueuee809b634-03a0-11e6-b719-e1aab88f48c3]]::FlowControl::delivery standard taking 253 from credits, available now is 1048323
2016-04-16 09:10:32,750 TRACE [org.apache.activemq.artemis.core.client] (Thread-259 (ActiveMQ-client-global-threads-582264346)) Adding Runner on Executor for delivery
2016-04-16 09:10:32,750 TRACE [org.apache.activemq.artemis.core.client] (Thread-260 (ActiveMQ-client-global-threads-582264346)) Calling handler.onMessage
2016-04-16 09:10:32,751 TRACE [org.apache.activemq.artemis.ra] (Thread-260 (ActiveMQ-client-global-threads-582264346)) onMessage(ClientMessage[messageID=79, durable=true, address=jms.queue.exampleQueue,userID=4f106b49-03a2-11e6-b719-e1aab88f48c3,properties=TypedProperties[__AMQ_CID=fb3a5265-03a1-11e6-b719-e1aab88f48c3]])

The Log information produced at TRACE level by org.apache.activemq is quite verbose. Consider using a more specific namespace for your needs. For example, if you want more details about the journaling, use rather the org.apache.activemq.artemis.journal.

com.arjuna

<logger category="com.arjuna">
         <level name="TRACE"/>
</logger>

This logger is already defined in your configuration out of the box, however it is set to a WARN level. You can consider increasing the severity of this logger if you want low level details about the transaction begin/commit/rollback. Here is a sample output of a successful transaction:

2016-04-16 09:12:11,426 TRACE [com.arjuna.ats.jta] (Thread-268 (ActiveMQ-client-global-threads-582264346)) TransactionImpleManager.suspend
2016-04-16 09:12:11,427 TRACE [com.arjuna.ats.jta] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BaseTransaction.begin
2016-04-16 09:12:11,427 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) StateManager::StateManager( 2, 0 )
2016-04-16 09:12:11,427 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BasicAction::BasicAction()
2016-04-16 09:12:11,427 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BasicAction::Begin() for action-id 0:ffff7f000001:12011438:5711e30d:3e
2016-04-16 09:12:11,427 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BasicAction::actionInitialise() for action-id 0:ffff7f000001:12011438:5711e30d:3e
2016-04-16 09:12:11,427 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) ActionHierarchy::ActionHierarchy(1)
2016-04-16 09:12:11,427 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) ActionHierarchy::add(0:ffff7f000001:12011438:5711e30d:3e, 1)
2016-04-16 09:12:11,427 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BasicAction::addChildThread () action 0:ffff7f000001:12011438:5711e30d:3e adding Thread[Thread-268 (ActiveMQ-client-global-threads-582264346),5,ActiveMQ-client-global-threads-582264346]
2016-04-16 09:12:11,427 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BasicAction::addChildThread () action 0:ffff7f000001:12011438:5711e30d:3e adding Thread[Thread-268 (ActiveMQ-client-global-threads-582264346),5,ActiveMQ-client-global-threads-582264346] result = true
2016-04-16 09:12:11,427 INFO  [stdout] (default task-40) Sent ActiveMQMessage[ID:89e17caa-03a2-11e6-b719-e1aab88f48c3]:PERSISTENT/ClientMessage[messageID=0, durable=true, address=null,userID=89e17caa-03a2-11e6-b719-e1aab88f48c3,properties=TypedProperties[__AMQ_CID=fb3a5265-03a1-11e6-b719-e1aab88f48c3]]
2016-04-16 09:12:11,428 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:12011438:5711e30d:3e status: ActionStatus.RUNNING, 300 )
2016-04-16 09:12:11,428 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:12011438:5711e30d:3e status: ActionStatus.RUNNING, 300 )
2016-04-16 09:12:11,428 TRACE [com.arjuna.ats.jta] (Thread-268 (ActiveMQ-client-global-threads-582264346)) TransactionImple.enlistResource ( org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@35c12a45 )
2016-04-16 09:12:11,428 TRACE [com.arjuna.ats.jta] (Thread-268 (ActiveMQ-client-global-threads-582264346)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2016-04-16 09:12:11,429 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) StateManager::StateManager( 1, 0 )
2016-04-16 09:12:11,429 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) AbstractRecord::AbstractRecord (0:ffff7f000001:12011438:5711e30d:40, 1)
2016-04-16 09:12:11,429 TRACE [com.arjuna.ats.jta] (Thread-268 (ActiveMQ-client-global-threads-582264346)) XAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:12011438:5711e30d:3e, node_name=1, branch_uid=0:ffff7f000001:12011438:5711e30d:3f, subordinatenodename=null, eis_name=java:/JmsXA NodeId:e809b634-03a0-11e6-b719-e1aab88f48c3 >, org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@35c12a45 ), record id=0:ffff7f000001:12011438:5711e30d:40
2016-04-16 09:12:11,430 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:12011438:5711e30d:40
2016-04-16 09:12:11,430 INFO  [stdout] (Thread-268 (ActiveMQ-client-global-threads-582264346)) Received message blank msg
2016-04-16 09:12:11,431 TRACE [com.arjuna.ats.jta] (Thread-268 (ActiveMQ-client-global-threads-582264346)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
2016-04-16 09:12:11,431 TRACE [com.arjuna.ats.jta] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BaseTransaction.commit
2016-04-16 09:12:11,431 TRACE [com.arjuna.ats.jta] (Thread-268 (ActiveMQ-client-global-threads-582264346)) TransactionImple.commitAndDisassociate
2016-04-16 09:12:11,431 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BasicAction::End() for action-id 0:ffff7f000001:12011438:5711e30d:3e
2016-04-16 09:12:11,431 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BasicAction::onePhaseCommit() for action-id 0:ffff7f000001:12011438:5711e30d:3e
2016-04-16 09:12:11,431 TRACE [com.arjuna.ats.jta] (Thread-268 (ActiveMQ-client-global-threads-582264346)) XAResourceRecord.topLevelOnePhaseCommit for XAResourceRecord < resource:org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@35c12a45, txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:12011438:5711e30d:3e, node_name=1, branch_uid=0:ffff7f000001:12011438:5711e30d:3f, subordinatenodename=null, eis_name=java:/JmsXA NodeId:e809b634-03a0-11e6-b719-e1aab88f48c3 >, heuristic: TwoPhaseOutcome.FINISH_OK, product: ActiveMQ Artemis/1.1.0.wildfly-011, jndiName: java:/JmsXA NodeId:e809b634-03a0-11e6-b719-e1aab88f48c3 com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@28b66a6c >, record id=0:ffff7f000001:12011438:5711e30d:40
2016-04-16 09:12:11,443 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BasicAction::End() result for action-id (0:ffff7f000001:12011438:5711e30d:3e) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
2016-04-16 09:12:11,443 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BasicAction::removeChildThread () action 0:ffff7f000001:12011438:5711e30d:3e removing TSThread:3
2016-04-16 09:12:11,443 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) BasicAction::removeChildThread () action 0:ffff7f000001:12011438:5711e30d:3e removing TSThread:3 result = true
2016-04-16 09:12:11,443 TRACE [com.arjuna.ats.arjuna] (Thread-268 (ActiveMQ-client-global-threads-582264346)) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:12011438:5711e30d:3e status: ActionStatus.COMMITTED )

org.jgroups

<logger category="org.jgroups">
         <level name="TRACE"/>
</logger>

JGroups is a key subsystem of the application server and the messaging layer of the cluster. When you are preparing to battle with cluster issues, tracing this subsystem can be vital to solve recover information about Failure detection (FD_SOCK) , UNICAST3 (For point-to-point communication), NAKACK2 (For multicast communication). Here is a sample dump from a org.jgroups trace output:

2016-04-16 09:24:32,109 TRACE [org.jgroups.protocols.UNICAST3] (OOB-18,ee,nodeA) nodeA <-- DATA(nodeB: #32, conn_id=0)
2016-04-16 09:24:32,109 TRACE [org.jgroups.protocols.UNICAST3] (OOB-18,ee,nodeA) nodeA: delivering nodeB#32
2016-04-16 09:24:32,109 TRACE [org.jgroups.protocols.UFC] (OOB-18,ee,nodeA) nodeB used 69 credits, 1996055 remaining
2016-04-16 09:24:32,109 TRACE [org.jgroups.blocks.RequestCorrelator] (OOB-18,ee,nodeA) calling (org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher) with request 25
2016-04-16 09:24:32,110 TRACE [org.jgroups.blocks.Request] (remote-thread--p5-t3) sending request (id=43)
2016-04-16 09:24:32,110 TRACE [org.jgroups.protocols.UNICAST3] (remote-thread--p5-t3) nodeA --> DATA(nodeB: #37, conn_id=2)
2016-04-16 09:24:32,110 TRACE [org.jgroups.protocols.UDP] (remote-thread--p5-t3) nodeA: sending msg to nodeB, src=nodeA, headers are RequestCorrelator: id=200, type=REQ, id=43, rsp_expected=false, FORK: ee:ejb, UNICAST3: DATA, seqno=37, conn_id=2, UDP: [cluster_name=ee]
2016-04-16 09:24:32,110 TRACE [org.jgroups.protocols.UFC] (remote-thread--p5-t3) nodeA used 939 credits, 1981588 remaining
2016-04-16 09:24:32,110 TRACE [org.jgroups.protocols.UDP] (TransferQueueBundler,ee,nodeA) nodeA: sending 1 msgs (1025 bytes (1.60% of max_bundle_size) to 1 dests(s): [ee:nodeB]
2016-04-16 09:24:32,111 TRACE [org.jgroups.blocks.RequestCorrelator] (remote-thread--p5-t3) sending rsp for 25 to nodeB
2016-04-16 09:24:32,111 TRACE [org.jgroups.protocols.UNICAST3] (remote-thread--p5-t3) nodeA --> DATA(nodeB: #38, conn_id=2)
2016-04-16 09:24:32,111 TRACE [org.jgroups.protocols.UDP] (remote-thread--p5-t3) nodeA: sending msg to nodeB, src=nodeA, headers are RequestCorrelator: id=200, type=RSP, id=25, rsp_expected=false, FORK: ee:ejb, UNICAST3: DATA, seqno=38, conn_id=2, UDP: [cluster_name=ee]
2016-04-16 09:24:32,111 TRACE [org.jgroups.protocols.UDP] (TransferQueueBundler,ee,nodeA) nodeA: sending 1 msgs (92 bytes (0.14% of max_bundle_size) to 1 dests(s): [ee:nodeB]
2016-04-16 09:24:32,141 TRACE [org.jgroups.protocols.UNICAST3] (Timer-3,ee,nodeA) nodeA --> ACK(nodeB: #32)
2016-04-16 09:24:32,142 TRACE [org.jgroups.protocols.UDP] (Timer-3,ee,nodeA) nodeA: sending msg to nodeB, src=nodeA, headers are UNICAST3: ACK, seqno=32, ts=9, UDP: [cluster_name=ee]
2016-04-16 09:24:32,142 TRACE [org.jgroups.protocols.UDP] (TransferQueueBundler,ee,nodeA) nodeA: sending 1 msgs (58 bytes (0.09% of max_bundle_size) to 1 dests(s): [ee:nodeB]
2016-04-16 09:24:32,178 TRACE [org.jgroups.protocols.UDP] (OOB-18,ee,nodeA) nodeA: received [dst: <null>, src: nodeB (4 headers), size=171 bytes, flags=OOB|DONT_BUNDLE|NO_TOTAL_ORDER], headers are RequestCorrelator: id=200, type=REQ, id=26, rsp_expected=true, FORK: ee:ejb, NAKACK2: [MSG, seqno=2], UDP: [cluster_name=ee]
2016-04-16 09:24:32,179 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (OOB-18,ee,nodeA) nodeA: received nodeB#2
2016-04-16 09:24:32,180 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (OOB-18,ee,nodeA) nodeA: delivering nodeB#2
2016-04-16 09:24:32,181 TRACE [org.jgroups.protocols.MFC] (OOB-18,ee,nodeA) nodeB used 171 credits, 1999585 remaining
2016-04-16 09:24:32,181 TRACE [org.jgroups.blocks.RequestCorrelator] (OOB-18,ee,nodeA) calling (org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher) with request 26
2016-04-16 09:24:32,182 TRACE [org.jgroups.blocks.RequestCorrelator] (remote-thread--p5-t3) sending rsp for 26 to nodeB
2016-04-16 09:24:32,183 TRACE [org.jgroups.protocols.UNICAST3] (remote-thread--p5-t3) nodeA --> DATA(nodeB: #39, conn_id=2)
2016-04-16 09:24:32,183 TRACE [org.jgroups.protocols.UDP] (remote-thread--p5-t3) nodeA: sending msg to nodeB, src=nodeA, headers are RequestCorrelator: id=200, type=RSP, id=26, rsp_expected=false, FORK: ee:ejb, UNICAST3: DATA, seqno=39, conn_id=2, UDP: [cluster_name=ee]
2016-04-16 09:24:32,183 TRACE [org.jgroups.protocols.UDP] (TransferQueueBundler,ee,nodeA) nodeA: sending 1 msgs (90 bytes (0.14% of max_bundle_size) to 1 dests(s): [ee:nodeB]
2016-04-16 09:24:32,206 TRACE [org.jgroups.protocols.UDP] (OOB-18,ee,nodeA) nodeA: received [dst: nodeA, src: nodeB (4 headers), size=79 bytes, flags=OOB|DONT_BUNDLE|NO_TOTAL_ORDER], headers are RequestCorrelator: id=200, type=REQ, id=27, rsp_expected=false, FORK: ee:ejb, UNICAST3: DATA, seqno=33, UDP: [cluster_name=ee]
2016-04-16 09:24:32,207 TRACE [org.jgroups.protocols.UNICAST3] (OOB-18,ee,nodeA) nodeA <-- DATA(nodeB: #33, conn_id=0)
2016-04-16 09:24:32,207 TRACE [org.jgroups.protocols.UNICAST3] (OOB-18,ee,nodeA) nodeA: delivering nodeB#33
2016-04-16 09:24:32,207 TRACE [org.jgroups.protocols.UFC] (OOB-18,ee,nodeA) nodeB used 79 credits, 1995976 remaining
2016-04-16 09:24:32,207 TRACE [org.jgroups.blocks.RequestCorrelator] (OOB-18,ee,nodeA) calling (org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher) with request 27

org.infinispan

<logger category="org.infinispan">
         <level name="TRACE"/>
</logger>

The Infinispan subsystem exposes a wealth of information about the clustering topology and the Data Grid Container. Hence we suggest you choosing a more specific namespace such as:

  • org.infinispan.remoting.transport.jgroups: This package traces information about the Infinispan-JGroups communication
  • org.infinispan.topology: This package traces information about changes in the Cluster topology
  • org.infinispan.container: This package exposes information about entries creation, update, removal

Here is a transcript from a Session item stored in the Cache:

2016-04-16 09:42:44,605 TRACE [org.infinispan.container.EntryFactoryImpl] (default task-3) Creating new entry for key UnknownSessionID [5465576970707067575552505248555566665248686865705255665754546649]
2016-04-16 09:42:44,605 TRACE [org.infinispan.container.EntryFactoryImpl] (default task-3) Wrap UnknownSessionID [5465576970707067575552505248555566665248686865705255665754546649] for read. Entry=RepeatableReadEntry(4d1bb5fb){key=UnknownSessionID [5465576970707067575552505248555566665248686865705255665754546649], value=org.wildfly.clustering.ejb.infinispan.bean.InfinispanBeanEntry@55ca0188, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, isExpired=false, skipRemoteGet=false, metadata=EmbeddedMetadata{version=null}}
2016-04-16 09:42:44,605 TRACE [org.infinispan.interceptors.CacheLoaderInterceptor] (default task-3) Skip load for command GetKeyValueCommand {key=UnknownSessionID [5465576970707067575552505248555566665248686865705255665754546649], flags=null}. Entry already exists in context.
2016-04-16 09:42:44,605 TRACE [org.infinispan.interceptors.CallInterceptor] (default task-3) Executing command: GetKeyValueCommand {key=UnknownSessionID [5465576970707067575552505248555566665248686865705255665754546649], flags=null}.
2016-04-16 09:42:44,605 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (default task-3) Invoked with command GetKeyValueCommand {key=f8009a1b-ab2a-470d-9734-d9c88d969c9a, flags=null} and InvocationContext [org.infinispan.context.impl.LocalTxInvocationContext@d84aa3f]
2016-04-16 09:42:44,605 TRACE [org.infinispan.statetransfer.StateTransferInterceptor] (default task-3) handleTopologyAffectedCommand for command GetKeyValueCommand {key=f8009a1b-ab2a-470d-9734-d9c88d969c9a, flags=null}, origin null
2016-04-16 09:42:44,605 TRACE [org.infinispan.container.EntryFactoryImpl] (default task-3) Exists in context? null
2016-04-16 09:42:44,605 TRACE [org.infinispan.container.EntryFactoryImpl] (default task-3) Retrieved from container ImmortalCacheEntry{key=f8009a1b-ab2a-470d-9734-d9c88d969c9a, value=org.wildfly.clustering.ejb.infinispan.group.InfinispanBeanGroupEntry@5baab53f} (ignoreOwnership=false, isLocal=true)
2016-04-16 09:42:44,605 TRACE [org.infinispan.container.EntryFactoryImpl] (default task-3) Creating new entry for key f8009a1b-ab2a-470d-9734-d9c88d969c9a
2016-04-16 09:42:44,606 TRACE [org.infinispan.container.EntryFactoryImpl] (default task-3) Wrap f8009a1b-ab2a-470d-9734-d9c88d969c9a for read. Entry=RepeatableReadEntry(12ba8a52){key=f8009a1b-ab2a-470d-9734-d9c88d969c9a, value=org.wildfly.clustering.ejb.infinispan.group.InfinispanBeanGroupEntry@5baab53f, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, isExpired=false, skipRemoteGet=false, metadata=EmbeddedMetadata{version=null}}
2016-04-16 09:42:44,606 TRACE [org.infinispan.interceptors.CacheLoaderInterceptor] (default task-3) Skip load for command GetKeyValueCommand {key=f8009a1b-ab2a-470d-9734-d9c88d969c9a, flags=null}. Entry already exists in context.
2016-04-16 09:42:44,606 TRACE [org.infinispan.interceptors.CallInterceptor] (default task-3) Executing command: GetKeyValueCommand {key=f8009a1b-ab2a-470d-9734-d9c88d969c9a, flags=null}.

And here is a dump of a change in the Cluster Topology:

2016-04-16 09:30:00,319 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (transport-thread--p15-t9) Updating local topology for cache client-mappings: CacheTopology{id=10, rebalanceId=3, currentCH=DefaultConsistentHash{ns=80, owners = (1)[nodeA: 80+0]}, pendingCH=null, unionCH=null, actualMembers=[nodeA]}
2016-04-16 09:30:00,319 DEBUG [org.infinispan.statetransfer.StateConsumerImpl] (transport-thread--p15-t9) Removing no longer owned entries for cache client-mappings
2016-04-16 09:30:00,320 DEBUG [org.infinispan.transaction.impl.TransactionTable] (transport-thread--p15-t9) Topology changed, recalculating minTopologyId
2016-04-16 09:30:00,321 DEBUG [org.infinispan.topology.ClusterCacheStatus] (remote-thread--p5-t4) Queueing rebalance for cache client-mappings with members [nodeA]
2016-04-16 09:30:00,322 TRACE [org.infinispan.topology.ClusterCacheStatus] (remote-thread--p5-t4) Rebalancing consistent hash for cache client-mappings, members are [nodeA]
2016-04-16 09:30:00,322 TRACE [org.infinispan.topology.ClusterCacheStatus] (remote-thread--p5-t4) The balanced CH is the same as the current CH, not rebalancing
2016-04-16 09:30:00,324 TRACE [org.infinispan.transaction.impl.AbstractEnlistmentAdapter] (notification-thread--p2-t1) Committed in onePhase? true isOptimistic? false
2016-04-16 09:30:00,324 TRACE [org.infinispan.transaction.impl.AbstractEnlistmentAdapter] (notification-thread--p2-t1) About to invoke tx completion notification on commitNodes: null
2016-04-16 09:30:00,395 DEBUG [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) New view accepted: [nodeA|6] (1) [nodeA]
2016-04-16 09:30:00,396 DEBUG [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) Joined: [], Left: [nodeB]
2016-04-16 09:30:00,396 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) ISPN000094: Received new cluster view for channel server: [nodeA|6] (1) [nodeA]
2016-04-16 09:30:00,397 DEBUG [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) New view accepted: [nodeA|6] (1) [nodeA]
2016-04-16 09:30:00,397 TRACE [org.infinispan.topology.ClusterTopologyManagerImpl] (transport-thread--p16-t6) Updating cluster members for all the caches. New list is [nodeA]
2016-04-16 09:30:00,397 DEBUG [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) Joined: [], Left: [nodeB]
2016-04-16 09:30:00,397 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) ISPN000094: Received new cluster view for channel web: [nodeA|6] (1) [nodeA]
2016-04-16 09:30:00,398 DEBUG [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) New view accepted: [nodeA|6] (1) [nodeA]
2016-04-16 09:30:00,399 DEBUG [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) Joined: [], Left: [nodeB]
2016-04-16 09:30:00,399 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) ISPN000094: Received new cluster view for channel hibernate: [nodeA|6] (1) [nodeA]
2016-04-16 09:30:00,400 DEBUG [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) New view accepted: [nodeA|6] (1) [nodeA]
2016-04-16 09:30:00,400 DEBUG [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) Joined: [], Left: [nodeB]
2016-04-16 09:30:00,400 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-15,ee,nodeA) ISPN000094: Received new cluster view for channel ejb: [nodeA|6] (1) [nodeA]

In the following tutorial we will cover how to debug WildFly Security Issues by enabling loggers:

How to debug WildFly security issues?

Use Camel to handle your WildFly logs

Many of you have heard about Camel rule based and mediation engine. On this tutorial we will show how to unleash its power to handle the logs from WildFly 9!

First of all, if you need a quickstart tutorial about Camel here is an Hello World Camel quickstart

In order to trigger Came routes, we will configure a Socket Handler on WildFly and then send our logs through TCP. Camel will listen on that Connection and handle your logs using one of its many Components available.

Step # 1: Download the Socket Handler API: a Socket Handler is not native on WildFly configuration, thus we need formerly download the JBoss log Manager extension.

Step # 2: You need to install the Log Manager as a module and assign it to an Handler. In our case, we will assign it to the ROOT handler:

batch
 
module add --name=org.jboss.logmanager.ext --dependencies=org.jboss.logmanager,javax.json.api,javax.xml.stream.api --resources=jboss-logmanager-ext-1.0.0.Alpha3.jar

/subsystem=logging/custom-handler=socket-handler:add(class=org.jboss.logmanager.ext.handlers.SocketHandler,module=org.jboss.logmanager.ext,named-formatter=PATTERN,properties={hostname=localhost, port=7080})

/subsystem=logging/root-logger=ROOT:add-handler(name=socket-handler)

:reload
run-batch

In the above CLI script, we have defined a new handler named “custom-handler” which is configured to send messages through a TCP connection to localhost and port 7080. Change the above settings to your needs.

Step # 3: Build a simple Camel route which acts as a Server for messages sent by WildFly:

package com.sample;

import org.apache.camel.Exchange;
import org.apache.camel.Processor;
import org.apache.camel.builder.RouteBuilder;
import org.apache.camel.main.Main;
 
public class TCPExample {

    public static void main(String[] args) throws Exception {
        Main main = new Main();
        main.enableHangupSupport();
        main.addRouteBuilder(new MyRouteTCP());
        main.run(args);
    }
}

class MyRouteTCP extends RouteBuilder {

    @Override
    public void configure() throws Exception {

        from("netty:tcp://localhost:7080?textline=true&sync=false").to("stream:out");

    }
}

The above code will use a Camel netty component to receive text line based TCP messages which will be redirected to a System.out stream. Nothing so fancy, but just enough to stretch our muscles! Remember you need to include the appropriate dependencies in order to run the above class:

<dependency>
	<groupId>org.apache.camel</groupId>
	<artifactId>camel-core</artifactId>
	<version>2.14.1</version>
</dependency>

		
<dependency>
	<groupId>org.apache.camel</groupId>
	<artifactId>camel-stream</artifactId>
	<version>2.14.1</version>
</dependency>


<dependency>
	<groupId>org.apache.camel</groupId>
	<artifactId>camel-netty</artifactId>
	<version>2.14.1</version>
</dependency>

Now start your Camel route and then start also WildFly Application server. You will see then your log messages flowing on Camel’s output console!

From now on it’s up to your imagination what to do with your logs. You can send them by email, to your DropBox account or store them on MongoDB. Here is just as an example, how you could filter for “ERROR” log messages and send them to a JMS Queue:

class MyRouteTCP extends RouteBuilder {

    @Override
    public void configure() throws Exception {

        from("netty:tcp://localhost:7080?textline=true&sync=false").process(new MyProcessor())
                .to("test-jms:queue:logQueue");

    }
}

class MyProcessor implements Processor {

    public void process(Exchange exchange) throws Exception {

        String myString = exchange.getIn().getBody(String.class);
        String[] myArray = myString.split(System.getProperty("line.separator"));
        StringBuffer sb = new StringBuffer();
        for (String s : myArray) {
            if (s.indexOf("ERROR") > -1) {
                sb.append(s);
            }
        }

        exchange.getIn().setBody(sb.toString());
    }

    public MyProcessor() {
    }

}

 Here you can get more details about configuring Camel to send messages to a JMS Queue running on JBoss EAP /WildFly.

 Have fun with Camel and WildFly!

Using a Logger for a specific application (EAP 6 and WildFly)

A common requirement for many applications is to use a specific logger to trace log events. In this recipe we will learn how to use Logging profiles to define a logger that can be activated at application level. This tutorial can be used with JBoss EAP 6.2 (and higher) and WildFly application server.

Let’s start from a sample. Here we have defined a File size based Handler and a Logger for intercepting the Handler:

<size-rotating-file-handler name="SIZE" autoflush="true">
	<level name="INFO"/>
	<file relative-to="jboss.server.log.dir" path="mylog.log"/>
	<append value="true"/>
</size-rotating-file-handler>
 
<logger category="com.mycompany" use-parent-handlers="false">
	<level name="INFO"/>
	<handlers>
		<handler name="SIZE"/>
	</handlers>
</logger>

The problem with the above logger is that you might have lots of applications using the com.mycompany namespace, therefore it is not so useful as you might think. One solution is to use a Logger profile which defines a named profiles that has to be activated at application level. Let’s see the above example rewritten:

<subsystem xmlns="urn:jboss:domain:logging:1.2">  
  ........  
  <logging-profiles>  
    <logging-profile name="myapp1">  
		<size-rotating-file-handler name="SIZE" autoflush="true">
				<level name="INFO"/>
				<file relative-to="jboss.server.log.dir" path="mylog.log"/>
				<append value="true"/>
		</size-rotating-file-handler>
		<logger category="com.mycompany" use-parent-handlers="false">
			<level name="INFO"/>
			<handlers>
				<handler name="SIZE"/>
			</handlers>
		</logger> 
    </logging-profile>  
  </logging-profiles>  
</subsystem> 

Now the handler and its Logger are wrapped by the loggin profile named “myapp1”. The last step will be including in the MANIFEST.MF file of your application a reference to the Logging profile so that it can be switched on by your application:

Manifest-Version: 1.0  
Class-Path:  
Logging-Profile: myapp1  

How do you set logging verbosity with JBoss 5 ?

The amount of logging is controlled by categories. Categories are named entities, which follow a hierarchical naming rule similar to Java packages. For example, the category named com.sample is a parent of the category named com.sample.Test .
Similarly, java is a parent of java.util and an ancestor of java.util.Vector.
Let’s see some samples of categories:

<category name="org.apache">
   <priority value="INFO"/>
</category>
<category name="org.jgroups">
   <priority value="WARN"/>
</category>

The first element limits the verbosity of org.apache packages to INFO , which means that this category will capture all logs in the priority—INFO, WARN, ERROR, and FATAL, but not TRACE and DEBUG levels.
The second one, WARN , is concerned with org.jgroups packages and starts capturing WARN, ERROR, and FATAL messages.

As we said, categories are hierarchical, so a category inherits its configuration from parent categories (unless it defines its own configuration). Similar to Java classes, which are extensions of the object class, all categories inherit from the root logger that resides at the top of the logger hierarchy.

This is the default root category configuration:

<root>
   <appender-ref ref="CONSOLE" />
   <appender-ref ref="FILE" />
</root>

The appender-ref elements tell the category which appenders will be used to
send the log messages. By default, JBoss is configured to capture the CONSOLE
and FILE appenders.

Managing logs through JMX agents

If you don’t have access to your configuration files, you can use the JMX console to get/set the logging parameters.
JBoss logging service is managed by Log4jService ( service=Logging,type=Log4jService ) in the jboss.system domain. Open up the JMX agent view pointing to Log4jService .
Besides changing the ConfigurationURL (that is where log4j.xml is placed) a useful parameter is the DefaultJBossServerLogThreshold , which lets you define the default log threshold for your applications.

Setting log4j verbosity in JBoss 5

JBoss AS 5.0 uses the system property jboss.system.log.threshold to define the verbosity of log4j.
By default this property is set to DEBUG (while in previous versions it was set to TRACE).If you want to specify a new setting you can simply issue:

run -Djboss.system.log.threshold=ERROR

Another way to change this setting is editing the server/xxx/conf/jboss-service.xml file.

Look for the attribute named DefaultJBossServerLogThreshold on the logging service MBean.