Monitoring Declarative Transactions in Spring

Designing a Solution with Logging

Class Loading

A transaction logging solution can be easily implemented for either Log4J or Java Logging, provided we watch out for class loading issues. Java Logging and typically Log4J are installed in a low-level class loader that does not have direct access to the Spring Framework classes needed to observe transaction status. Fortunately for us, Spring classes are accessible at runtime from the 'context class loader' attached to each thread. Using the context class loader and a little reflection, it's possible to invoke methods on TransactionSynchronizationManager to determine transaction status. The code below demonstrates how to determine the status for the current thread via reflection:

public class TransactionIndicatingUtil {
    private final static String TSM_CLASSNAME = "org.springframework.transaction.support.TransactionSynchronizationManager";

    public static String getTransactionStatus(boolean verbose) 
{
        String status = null;

        try {
            ClassLoader contextClassLoader = Thread.currentThread().getContextClassLoader();
            if (contextClassLoader != null) 
           {
                Class tsmClass = contextClassLoader.loadClass(TSM_CLASSNAME);
                Boolean isActive = (Boolean) tsmClass.getMethod("isActualTransactionActive", null).invoke(null, null);
                if (!verbose) {
                    status = (isActive) ? "[+] " : "[-] ";
                } 
               else {
                    String transactionName = (String) tsmClass.getMethod("getCurrentTransactionName", null).invoke(null, null);
                    status = (isActive) ? "[" + transactionName + "] " : "[no transaction] ";
                }            
         }           
         else 
        {
                status = (verbose) ? "[ccl unavailable] " : "[x ]";
            }
        } catch (Exception e) {
            status = (verbose) ? "[spring unavailable] " : "[x ]";
        } 
       return status;
    }

Plugging into Log4J

The ideal point to plug into the Log4J framework is at the Filter level. Filters intercept logging messages before they reach an Appender in Log4J (i.e., ConsoleAppender, FileAppender). We can create a filter that adds information to the MappedDiagnosticContext, or MDC, of the logging event. The MDC is essentially a Map of name/value pairs that are available to an Appender for output. Here's our filter implementation that adds a 'xaName' and 'xaStatus' property to the MDC: 

import static com.skillcorp.transactionlogger.TransactionIndicatingUtil.*;
...
public class TransactionIndicatingFilter extends Filter {
    @Override
    public int decide(LoggingEvent loggingEvent) {
        loggingEvent.setProperty("xaName", getTransactionStatus(true) );
        loggingEvent.setProperty("xaStatus", getTransactionStatus(false) );
        return Filter.NEUTRAL;
    }  
}

   <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
      <param name="Target" value="System.out"/>
      <param name="Threshold" value="INFO"/>
      <layout class="org.apache.log4j.PatternLayout">
         <!-- The default pattern: Date Priority [Category] Message\n --> 
        <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p [%c{1}] %X{xaStatus}- %m%n"/>
      </layout>      
      <filter class="com.skillcorp.transactionlogger.log4j.TransactionIndicatingFilter"/>
   </appender>

public class TransactionIndicatingConsoleAppender extends org.apache.log4j.ConsoleAppender {
    public TransactionIndicatingConsoleAppender() 
{
        addFilter(new TransactionIndicatingFilter()); 
   }
}

Plugging into Java Logging

The logging framework built into Java also has a Filter layer that can be leveraged to insert our transaction decoration, but it does not have an analog to the MappedDiagnosticContext used with Log4J. To add our decoration in this case requires that we directly modify the application message in the logging record:

import static com.skillcorp.transactionlogger.TransactionIndicatingUtil.*;
public class TransactionIndicatingFilter implements Filter {
...
    @Override
    public boolean isLoggable(LogRecord record) {
        record.setMessage(getTransactionStatus(isVerbose()) + record.getMessage());
        return true;
    }
...
}

Configuration is an additional wrinkle for the Java Logging filter. The transaction status can be indicated in either a terse or verbose format, selectable by the argument to getTransactionStatus(). In the Log4J filter above, the system simply adds both terse and verbose status fields to the MDC, and allows the appender / formatter to determine the correct log output. Since the MDC is not available in Java Logging, the filter must be configured to choose the correct output. The LogManager class exposes properties from the logging configuration file (default location: $JRE_HOME/lib/logging.properties)

    public TransactionIndicatingFilter() {
        String $verbose = LogManager.getLogManager().getProperty(TransactionIndicatingFilter.class.getName() + ".verbose");
        if ($verbose != null) {
            verbose = Boolean.parseBoolean($verbose);
        }
    }

java.util.logging.ConsoleHandler.level = INFO
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
java.util.logging.ConsoleHandler.filter = com.skillcorp.transactionlogger.jdklog.TransactionIndicatingFilter
com.skillcorp.transactionlogger.jdklog.TransactionIndicatingFilter.verbose=true

An Implementation

You can access a Maven-based project with the source code and test cases for demonstrating the decorated output for each logging framework. A binary of the logging solution is also available here

Article Resources: 

transactionLogger-1.0.2-SNAPSHOT.jar

transactionLogger-1.0.2-SNAPSHOT-project.zip