Customize your log message

        用Log4j很久了，一直没有好好的琢磨它。最近有个需求是这样的： 当用户操作导致异常发生的时候，要能够知道是那个用户在操作什么的时候导致了异常的发生。异常发生通常意味着给我们的customer带来不好的体验，如果我们能够知道是谁在experience它，我们的client service就可以跟进，通过email或者其他形式给用户一个合理的解释。毕竟，用户就是上帝嘛。:-)
        这里我略过log4j的使用介绍，直接进入主题。想知道用户的信息很简单，我们一般会把用户的信息存放在session中，所以直接思路就是做一个Filter，在其中取到用户名和当前用户请求的URI。在webwork(Struts2)中，我们还想知道的更详细一点，就是当前执行的action的信息，于是我们需要一个Interceptor，在Interceptor中可以获知当前正在调用的Action的信息。然后是最重要的一点，我们需要把这个customized的信息添加到我们的log message 里面。
        于是我想到了MDC（org.apache.log4j.MDC）, 它是一个ThreadLocal的Map， 所以可以保证我们存放在其中的customized信息不会混淆。它提供了static的put方法，于是我们如下操作：

MDC.put("username",username);
MDC.put("uri",uri);
MDC.put("actionjName",actionName);
...

       到了这里，剩下的工作就是把它展示出来了。让我们扩展一下某个Layout：

java 代码

public class MyLayout extends Layout {
    StringBuffer sbuf = new StringBuffer(128);
    @Override
    public void activateOptions() {
    }

    @Override
    public String format(LoggingEvent event) {
        sbuf.setLength(0);
        sbuf.append(new Date(event.getStartTime()).toLocaleString()).append(LINE_SEP);
        sbuf.append("|username:").append(MDC.get("username")).append(" | ");
        sbuf.append("uri:").append(MDC.get("uri")).append(" |").append(LINE_SEP);
        sbuf.append(event.getLevel().toString());
        sbuf.append(" - ");
        sbuf.append(event.getRenderedMessage()).append(LINE_SEP);
        String[] strs = event.getThrowableStrRep();
        if(strs != null ) {
            for(String str: event.getThrowableStrRep()) {
                sbuf.append(str).append(LINE_SEP);
            }
        }
        sbuf.append(LINE_SEP);
        return sbuf.toString();
    }

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

Ok了，把log4j中你所用的Appender的layout设置成你自己的layout吧：

例如：

log4j.appender.stdout.layout=com.jiny.learn.log.MyLayout

        然后看看你的Log message， 是不是帅多了？

java 代码

2007-7-26 13:57:01
|username:jiny | uri:/afterLogin |  actionName: AfterLoginAction
ERROR - I catched you!
java.lang.Exception: TestException
at com.jiny.learn.servlet.AfterLoginServlet.doProcess(AfterLoginServlet.java:14)
at com.jiny.learn.servlet.BaseServlet.doGet(BaseServlet.java:24)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:491)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1074)
at com.jiny.learn.log.LoggerContextFilter.doFilter(LoggerContextFilter.java:25)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1065)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:365)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:185)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:689)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:391)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
at org.mortbay.jetty.Server.handle(Server.java:285)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:457)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:751)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:500)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:209)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:357)
at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:217)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:475)