结合jeesite开发平台谈谈logger类的使用

logger类简介

java开发过程中经常需要打印日志信息，往往会在每个类的第一行加上形如以下代码：

protected static final Logger logger = LoggerFactory.getLogger(XXX.class);

目的：使用指定的类XXX初始化日志对象，方便在日志输出的时候，可以打印出日志信息所属的类。

looger在jeesite项目中的应用

1    protected AuthenticationInfo doGetAuthenticationInfo(AuthenticationToken authcToken) {
2		UsernamePasswordToken token = (UsernamePasswordToken) authcToken;
3
4		int activeSessionSize = getSystemService().getSessionDao().getActiveSessions(false).size();
5		if (logger.isDebugEnabled()) {
6			logger.debug("login submit, active session size: {}, username: {}", activeSessionSize, token.getUsername());
7		}
8
9		// 校验登录验证码
10		if (LoginController.isValidateCodeLogin(token.getUsername(), false, false)) {
11			Session session = UserUtils.getSession();
12			String code = (String) session.getAttribute(ValidateCodeServlet.VALIDATE_CODE);
13			if (token.getCaptcha() == null || !token.getCaptcha().toUpperCase().equals(code)) {
14				throw new AuthenticationException("msg:验证码错误, 请重试.");
15			}
16		}
17
18		// 校验用户名密码
19		User user = getSystemService().getUserByLoginName(token.getUsername());
20		if (user != null) {
21			if (Global.NO.equals(user.getLoginFlag())) {
22				throw new AuthenticationException("msg:该已帐号禁止登录.");
23			}
24			byte[] salt = Encodes.decodeHex(user.getPassword().substring(0, 16));
25			return new SimpleAuthenticationInfo(new Principal(user, token.isMobileLogin()),
26					user.getPassword().substring(16), ByteSource.Util.bytes(salt), getName());
27		} else {
28			return null;
29		}
30	}

上图是jeesite项目里的认证回调函数，主要是在登录时调用的。我们可以看到logger在代码片中的第5、6行得到了应用，主要是isDebugEnabled()以及debug()函数的使用。下面是两个函数的源码：

1  public boolean isDebugEnabled() {    
2    if(repository.isDisabled( Level.DEBUG_INT))
3        return false;
4    return Level.DEBUG.isGreaterOrEqual(this.getEffectiveLevel());
5  }

1 public void debug(Object message) {
2     if(repository.isDisabled(Level.DEBUG_INT))
3         return;
4     if(Level.DEBUG.isGreaterOrEqual(this.getEffectiveLevel())) {
5         forcedLog(FQCN, Level.DEBUG, message, null);
6     }
7 }

由上图可见，在debug()中做了跟isDebugEnabled()几乎一样的判断，这样用isDebugEnabled()去包含debug()函数岂不是做了重复的判断了吗，这样是否显得代码冗余了呢？下面看到：

logger.debug("login submit, active session size: {}, username: {}", activeSessionSize, token.getUsername());

首先我们假设我们的日志级别设置为info，debug()方法调用后,首先会通过repository.isDisabled()判断日志等级是否为DEBUG_INT，然后执行return。但是在调用debug()方法时，必须提供参数。而要获得参数，如上图所示就需要执行getActiveSessions()函数来获取activeSessionSize(即动态缓存大小)和token.getUsername()函数来获取用户的用户名信息。
假设这个获取诺干参数的过程需要5秒钟，则系统会在花费5秒后才会继续执行下面的代码逻辑，这从时间代价上来看是很低价的行为。而加上logger.isDebugEnabled()判断，只会使写日志的时间增加大概万分之一，但是如果不预先加上此判断，系统可能需要花费更多的时间去处理数据，所以在大多数情况下，在输出debug日志前加上logger.isDebugEnabled()函数进行日志等级判断会使得系统运行的效率更高。