有效地记录日志可以简化企业开发过程
日志非常好的实践
关于日志,您要做的一个最重要的选择可能是确定一种模式,将每个日志消息分配给一个特定的 类别。常见的一种实践是使用每个类的全名,这些类的操作会被作为一个消息类别在日志中记录(正如我们在清单 1 中看到的一样),这是因为这可以让开发人员更细粒度地记录每个类的设置。然而,这只有在使用日志消息来跟踪执行过程时才能良好地工作。在企业级的应用程序中,有很多其他类型的日志消息。举例来说,一条日志消息可能是为安全顾问产生的,而另外一条日志消息则可能是会为了帮助进行性能调优而产生的。如果这两条消息所关注的是同一个类,这样就会被分配给相同的类别,这将很难在日志输出结果中对其进行区分。
为了避免这个问题,应用程序应该具有一组专用的日志记录程序,它们都进行了独特的分类,如清单 3 所示。每个日志记录程序都可以配置自己的优先级和输出处理程序。例如,安全性日志记录程序可以在将日志写入目的地之前对消息进行加密。有时应用程序的设计者应该与使用日志的用户(例如安全顾问)一起来商讨日志的输出格式,从而对这些消息进行更好的控制。
清单 3. 专用的日志记录程序
import org.apache.log4j.Logger;
public interface Loggers {
Logger performance = Logger.getLogger("performance");
Logger security = Logger.getLogger("security");
Logger business = Logger.getLogger("business");
}
...
public class MyClass {
....
if (Loggers.security.isWarnEnabled()) {
Loggers.security.warn("Access denied: Username [" + userName + "] ...");
}
...
}
选择日志的级别
一个类别 (例如 security)中的消息可以具有不同的 优先级。有些消息是为了调试而产生的,有些是为了警告而产生的,有些则是出现错误而产生的。消息的不同优先级可以通过记录级别 来产生。最常用的日志级别有:
Debug:这个级别的消息中包含了非常广泛的上下文信息。通常用于问题诊断。
Info:这些消息包含了一些有助于在产品环境中(粒度较粗)帮助跟踪执行过程的上下文消息。
Warning:警告消息,说明系统中可能存在问题。例如,如果这个消息类别是有关安全性方面的,那么如果检测到字典攻击,就应该产生一条警告消息。
Error:错误消息说明系统中出现了严重的问题。这种问题通常都是不可恢复的,需要人工进行干预。
标准的 Java Logging API 和 Apache Log4J 在此之外又提供了一些日志级别。日志级别的主要目标是帮助您过滤有用信息中的噪声。为了防止出现使用错误的级别以及降低日志消息的效用的情况,在开始编码之前,必须为开发人员提供一个清晰的指导方针。
日志消息的格式
一旦选定日志记录程序并建立起日志级别之后,就可以开始构建日志消息了。在这样做时,重要的是要包含尽可能多的上下文信息,例如用户提供的参数,其他应用程序的状态信息。记录日志对象的一种方法是将它们转换成 XML。第三方库,例如 XStream可以自动将 Java 对象转换成 XML 。尽管这是一种非常强大的机制,但是我们必须要考虑在速度与详细程度之间达到一种平衡。除了典型的应用程序状态信息之外,还应该记录以下信息:
线程 ID:企业级的应用程序通常都是在多线程的环境中运行的。使用线程 ID 信息,您就可以将多个请求区分开来。
调用程序的标识:调用程序的标识也是非常重要的信息。由于不同的用户具有不同的特权,它们的执行路径也可能会有很大的不同。将用户的标识放到日志消息中,这对于对安全性敏感的应用程序是非常大的一个帮助。
时间戳:通常来说,用户只能近似地知道问题发生的时间。如果没有时间戳,就很难让别人来判断问题的原因所在。
源代码信息:这包括类名、方法名和行号。除非您非常关注安全性,否则我建议您保留调试标记(-g),即使在编译产品时也是如此。如果没有调试标记,Java 编译器就会删除所有的行号信息,从而极大地减少日志消息的可用性。
上面这些信息(除了调用程序标识)都是由日志实现自动获取的。为了将这些信息包含到消息中,您只需要为输出处理程序配置一个适当的 layout 模式即可。要捕获调用者的标识,您可以利用 Log4J 中的诊断上下文特性。诊断上下文让您可以将上下文信息与当前正在运行的线程关联在一起。这些信息可以在为输出进行格式化的同时而包含到每条消息中。
在 J2EE Web 应用程序中,应用逻辑将用户标识保存到诊断上下文中最好的地方是在一个 servlet 过滤器中。清单 4 中显示了要实现这种功能的必要代码。它使用了 Log4J 1.3 alpha 中提供的映射诊断上下文类(MDC)。您可以使用 Log4J 1.2 中提供的嵌套诊断上下文(NDC)实现相同的功能。有关 servlet 过滤器的更多通用信息,请参阅 参考资料 中的信息。
清单 4. 在 servlet 过滤器中使用诊断上下文
import javax.servlet.Filter;
...
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpSession;
import org.apache.log4j.MDC;
public class LoggerFilter implements Filter {
public void doFilter(ServletRequest request, ServletResponse response,
FilterChain chain) throws IOException, ServletException {
// Retrieves the session object from the current request.
HttpSession session = ((HttpServletRequest)request).getSession();
// Put the username into the diagnostic context.
// Use %X{username} in the layout pattern to include this information.
MDC.put("username", session.getAttribute("username"));
// Continue processing the rest of the filter chain.
chain.doFilter(request, response);
// Remove the username from the diagnostic context.
MDC.remove("username");
}
...
}
使用 AspectJ 跟踪执行情况
在对问题进行诊断时,通常跟踪程序的执行情况会很有帮助。您可以在程序执行的不同地方持续发送日志消息吗?例如方法的入口函数和出口函数。这是一个老问题,在出现 AspectJ 之前一直都没有什么好的解决方案。使用 AspectJ,可以在应用程序的不同地方执行代码段。在 AspectJ 中,这些地方都称为 point cut,在 point cut 处所执行的代码称为 advice。point cut 和advice 合称 aspect。
关于 AspectJ,有一件事情非常神奇,aspect 不用很多努力就可以应用到整个应用程序中。清单 5 给出了一个 AspectJ 源文件的例子,它用来对方法的入口和出口函数记录日志。在这个例子中,跟踪日志程序将在每次进入或退出 com.ambrosesoft 包的一个共有方法时都会记录一条日志。
清单 5. 使用 AspectJ 记录方法的入口和出口
import org.apache.log4j.Logger;
import java.lang.reflect.Field;
public aspect AutoTrace {
private static final Logger logger = Logger.getLogger(AutoTrace.class);
pointcut publicMethods() : execution(public * com.ambrosesoft..*(..));
pointcut loggableCalls() : publicMethods();
/**
* Inspect the class and find its logger object. If none is found, use
* the one defined here.
*/
private Logger getLogger(org.aspectj.lang.JoinPoint joinPoint) {
try {
/*
* Try to discover the logger object.
* The logger object must be a static field called logger.
*/
Class declaringType = joinPoint.getSignature().getDeclaringType();
Field loggerField = declaringType.getField("logger");
loggerField.setAccessible(true);
return (Logger)loggerField.get(null);
} catch(NoSuchFieldException e) {
/*
* Cannot find a logger object, use the internal one.
*/
return logger;
} catch(Exception e) {
throw new RuntimeException(e);
}
}
/**
* An aspect to log method entry.
*/
before() : loggableCalls(){
getLogger(thisJoinPoint).debug("Entering.." + thisJoinPoint.getSignature().toString());
}
/**
* An aspect to log method exit.
*/
after() : loggableCalls(){
getLogger(thisJoinPoint).debug("Exiting.." + thisJoinPoint.getSignature().toString());
}
}
0
相关文章