Showing a Spring transaction in log

Question

in your log4j.properties (for alternative loggers, or log4j's xml format, check the docs)

Depending on your transaction manager, you can set the logging level of the spring framework so that it gives you more info about transactions. For example, in case of using JpaTransactionManager, you set

log4j.logger.org.springframework.orm.jpa=INFO

(this is the package of the your transaction manager), and also

log4j.logger.org.springframework.transaction=INFO

If INFO isn't enough, use DEBUG

For me, a good logging config to add was:

log4j.logger.org.springframework.transaction.interceptor = trace

It will show me log like that:

2012-08-22 18:50:00,031 TRACE - Getting transaction for [com.MyClass.myMethod]

[my own log statements from method com.MyClass.myMethod]

2012-08-22 18:50:00,142 TRACE - Completing transaction for [com.MyClass.myMethod]

For Spring Boot application with application.properties

logging.level.ROOT=INFO
logging.level.org.springframework.orm.jpa=DEBUG
logging.level.org.springframework.transaction=DEBUG

or if you prefer Yaml (application.yaml)

logging:
   level:
      org.springframework.orm.jpa: DEBUG
      org.springframework.transaction: DEBUG

Most interesting log informations of JtaTransactionManager.java (if this question is still about the JtaTransactionManager) are logged at DEBUG priority. Assuming you have a log4j.properties somewhere on the classpath, I'd thus suggest to use:

log4j.logger.org.springframework.transaction=DEBUG

You could enable JDBC logging as well:

log4j.logger.org.springframework.jdbc=DEBUG

Because you can access Spring classes at runtime, you can determine transaction status. This article may help you:

https://dzone.com/articles/monitoring-declarative-transac

Here is some code I use in my Logback Layout implementation derived from ch.qos.logback.core.LayoutBase.

I create a thread-local variable to store the reference to the method org.springframework.transaction.support.TransactionSynchronizationManager.isActualTransactionActive(). Whenever a new log line is printed out, getSpringTransactionInfo() is called and it returns a one-character string that will go into the log.

References:

• Tips for Debugging Spring's @Transactional Annotation
• org.springframework.transaction.support.TransactionSynchronizationManager
• java.lang.ThreadLocal
• java.lang.Class.getMethod()

Code:

private static ThreadLocal<Method> txCheckMethod;

private static String getSpringTransactionInfo() {
    if (txCheckMethod == null) {
        txCheckMethod = new ThreadLocal<Method>() {
            @Override public Method initialValue() {           
                try {
                    ClassLoader contextClassLoader = Thread.currentThread().getContextClassLoader();
                    Class<?> tsmClass = contextClassLoader.loadClass("org.springframework.transaction.support.TransactionSynchronizationManager");
                    return tsmClass.getMethod("isActualTransactionActive", (Class<?>[])null);
                } catch (Exception e) {
                    e.printStackTrace();
                    return null;
                }                      
            }
         };    
    }
    assert txCheckMethod != null;
    Method m = txCheckMethod.get();
    String res;
    if (m == null) {
        res = " "; // there is no Spring here
    }
    else {
        Boolean isActive = null;
        try {
            isActive = (Boolean) m.invoke((Object)null);
            if (isActive) {
                res = "T"; // transaction active                    
            }
            else {
                res = "~"; // transaction inactive
            }
        }
        catch (Exception exe) {
            // suppress 
            res = "?";
        }
    }
    return res;
}