Grails logging - Is there any existing solution to be able to log the File + Line where the call actually occured?

Question

I'm new to Grails and I'm trying to configure Log4j so it logs the exact file and line where the log call occured. No pattern works as the conversionPattern! It seems Grails wraps the logger in a way that Log4j doesn't see the real source of the call.

I'm aware of this thread, but I'm not sure how to create a custom appender. I just can't believe nobody already developed something to fix this issue!

I'm open to any suggestions :

• Does using something else than Log4j work in Grails to get the actual file+line (Logback?)?
• Anyone with an existing "custom appender" he's willing to share?

Thanks in advance!

Answer 1

I actually did it by myself. I guess I should do a proper Grails plugin for it, but I'm still not comfortable enough with Grails to be sure the code will always work. I tested it by logging from a Controller and from a Service, using Grails 2.2.4, and it seems to work well.

It works by checking the stacktrace to find the actual file and line where the call occurred and then it adds this information in the MDC thread context. Values added to MDC can be used by the (other) appenders using the %X{fileAndLine} token.

Here's the code and the javadoc (read it!) :

package logFileLineInjectorGrailsPlugin

import org.apache.log4j.Appender;
import org.apache.log4j.AppenderSkeleton;
import org.apache.log4j.spi.LoggingEvent;
import org.apache.log4j.Logger;
import java.lang.StackTraceElement;
import org.apache.log4j.MDC;

/**
 * Allows the log appenders to have access to the FILE and LINE where the log call actually occurred.
 * 
 * (1) Add this pseudo appender to your other appenders, in Config.groovy. Then you can use 
 * "%X{fileAndLine}" in the other appenders to output the file and line where the log call actually occurred.
 * 
 * ------------
 * log4j = {
 *     appenders {
 *      appender name:'fileAndLineInjector', new logFileLineInjectorGrailsPlugin.FileAndLineInjector()
 *      // example of a console appender using the "%X{fileAndLine}" token :
 *         console name:'stdout', layout:pattern(conversionPattern: '[%d{yyyy-MM-dd HH:mm:ss}] %-5p ~ %m ~ %c ~ %X{fileAndLine}%n')
 *     }
 *  (...)
 * ------------
 * 
 * (2) Then add it has the *first* appender reference in the declarations of the loggers in which you want to use the "%X{fileAndLine}" token.
 *  
 * For example :
 * 
 * ------------
 * root {
 *     error 'fileAndLineInjector', 'stdout'
 * }
 * ------------
 *  
 * With this setup in place, a call to log.error("test!") will result in something like :
 *  
 * [2013-08-12 19:16:15] ERROR ~ test! ~ grails.app.services.testProject.TestService ~ (TestService.groovy:8)
 * 
 * In Eclipse/STS/GGTS (I didn't try in other IDEs), when "%X{fileAndLine}" is outputed in the internal console, the text is clickable
 * and leads to the actual file/line.
 * 
 *
 */
class FileAndLineInjector extends AppenderSkeleton {

    @Override
    public void close() {
    }

    @Override
    public boolean requiresLayout() {
        return false;
    }

    @Override
    protected void append(LoggingEvent event) {

        StackTraceElement[] strackTraceElements = Thread.currentThread().getStackTrace();

        StackTraceElement targetStackTraceElement = null;
        for(int i = 0; i < strackTraceElements.length; i++) {
            StackTraceElement strackTraceElement = strackTraceElements[i];
            if(strackTraceElement != null &&
               strackTraceElement.declaringClass != null &&
               strackTraceElement.declaringClass.startsWith("org.apache.commons.logging.Log\$") &&
               i < (strackTraceElements.length - 1)) {
                   targetStackTraceElement = strackTraceElements[++i];
                   while(targetStackTraceElement.declaringClass != null &&
                         targetStackTraceElement.declaringClass.startsWith("org.codehaus.groovy.runtime.callsite.") &&
                         i < (strackTraceElements.length - 1)) {
                       targetStackTraceElement = strackTraceElements[++i];
                   }
                   break;
            }
        }

        if(targetStackTraceElement != null) {
            MDC.put("fileAndLine", "(" + targetStackTraceElement.getFileName() + ":" + targetStackTraceElement.getLineNumber() + ")");
        } else {
            MDC.remove("fileAndLine");
        }
    }
}

Let me know if something is not clear or if you find a way to improve it!