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方法，于是我们如下操作：

 

1. MDC.put("username",username);  
2. MDC.put("uri",uri);  
3. MDC.put("actionjName",actionName);  
4. ...  

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

java 代码

 

1. public class MyLayout extends Layout {  
2.     StringBuffer sbuf = new StringBuffer(128);  
3.     @Override  
4.     public void activateOptions() {  
5.     }  
6.   
7.     @Override  
8.     public String format(LoggingEvent event) {  
9.         sbuf.setLength(0);  
10.         sbuf.append(new Date(event.getStartTime()).toLocaleString()).append(LINE_SEP);  
11.         sbuf.append("|username:").append(MDC.get("username")).append(" | ");  
12.         sbuf.append("uri:").append(MDC.get("uri")).append(" |").append(LINE_SEP);  
13.         sbuf.append(event.getLevel().toString());  
14.         sbuf.append(" - ");  
15.         sbuf.append(event.getRenderedMessage()).append(LINE_SEP);  
16.         String[] strs = event.getThrowableStrRep();  
17.         if(strs != null ) {  
18.             for(String str: event.getThrowableStrRep()) {  
19.                 sbuf.append(str).append(LINE_SEP);  
20.             }  
21.         }  
22.         sbuf.append(LINE_SEP);  
23.         return sbuf.toString();  
24.     }  
25.   
26.     @Override  
27.     public boolean ignoresThrowable() {  
28.         return false;  
29.     }  
30. }  

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

例如：

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

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

java 代码

 

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