SLF4J与Log4j实现日志记录

1 Introduction

没什么介绍…只是记录一下自己的使用习惯

Maven

<slf4j.version>1.7.7</slf4j.version>

<dependency>
    <groupId>org.slf4j</groupId>        <artifactId>slf4j-api</artifactId>
    <version>${slf4j.version}</version>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-log4j12</artifactId>
    <version>${slf4j.version}</version>
    </dependency>
<!-- common-logging 实际调用slf4j -->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>jcl-over-slf4j</artifactId>
    <version>${slf4j.version}</version>
</dependency>
<!-- java.util.logging 实际调用slf4j -->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>jul-to-slf4j</artifactId>
    <version>${slf4j.version}</version>
</dependency>

2 Log4J的配置

其中tabook为项目的名字

# log4j.properties
# Output pattern : date thread priority [category] - message   FATAL 0  ERROR 3  WARN 4  INFO 6  DEBUG 7
log4j.rootLogger=WARN, Console, RollingFile, ErrorRollingFile

#Console
log4j.appender.Console=org.apache.log4j.ConsoleAppender
log4j.appender.Console.layout=org.apache.log4j.PatternLayout
log4j.appender.Console.layout.ConversionPattern=%d %-5p [%c{5}] - %m%n

#RollingFile
log4j.appender.RollingFile=org.apache.log4j.DailyRollingFileAppender
log4j.appender.RollingFile.File=../logs/tabook/tabook.log
log4j.appender.RollingFile.layout=org.apache.log4j.PatternLayout
log4j.appender.RollingFile.layout.ConversionPattern=%d [%t] %-5p [%c] - %m%n

#ErrorRollingFile
log4j.appender.ErrorRollingFile=org.apache.log4j.DailyRollingFileAppender
log4j.appender.ErrorRollingFile.Threshold=Error
log4j.appender.ErrorRollingFile.File=../logs/tabook/tabook_error.log
log4j.appender.ErrorRollingFile.layout=org.apache.log4j.PatternLayout
log4j.appender.ErrorRollingFile.layout.ConversionPattern=%d [%t] %-5p [%c] -%m%n


log4j.logger.com.nevercome.tabook=DEBUG
log4j.logger.com.nevercome.tabook.common.security.shiro=WARN
log4j.logger.com.nevercome.tabook.common.utils.JedisUtils=WARN
log4j.logger.com.nevercome.tabook.modules.sys.web.LoginController=WARN
#log4j.logger.com.thinkgem.jeesite.modules.oa.dao.OaNotifyDao.findCount=WARN

3 测试使用

分别在log4j的配置文件中定义日志级别的包下进行测试。
观察控制台与两个日志文件的输出

import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
 * @author: sun
 * @date: 2019/4/5
 */
public class LogTest {
    private Logger logger = LoggerFactory.getLogger(getClass());

    // 如果你直接运行了Test，可能会问
    // 为什么没有输出到配置的目录？
    // 其实它是输出到配置的目录了
    // 因为你以为配置的目录的相对路径是web容器启动之后的logs
    // 它不是没有输出，而是在别的地方
    @Test
    public void logTest() {
        logger.info("I'm {} message", "info");
        logger.debug("I'm {} message", "debug");
        logger.warn("I'm {} message", "warn");
        logger.error("I'm {} message", "error");
    }
}

4 拦截器Interceptor与日志

与日志记录说在一起的技术通常有切面AOP、过滤器Filter，拦截器Interceptor。每种技术当然各有特点…拦截也好过滤也罢在技术与应用细节上有许多不同，但其核心思想都是在一个或系列动作、事件的一个或某些时刻插入进去进行自己的操作。

代码出自JeeSite快速开发框架，请求拦截，进行日志记录。

import com.nevercome.tabook.common.mapper.JsonMapper;
import com.nevercome.tabook.common.service.BaseService;
import com.nevercome.tabook.common.utils.DateUtils;
import com.nevercome.tabook.modules.sys.utils.LogUtils;
import org.springframework.core.NamedThreadLocal;
import org.springframework.web.servlet.HandlerInterceptor;
import org.springframework.web.servlet.ModelAndView;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.text.SimpleDateFormat;
import java.util.Map;

/**
 * 日志拦截器
 */
public class LogInterceptor extends BaseService implements HandlerInterceptor {

    private static final ThreadLocal<Long> startTimeThreadLocal =
            new NamedThreadLocal<Long>("ThreadLocal StartTime");

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response,
                             Object handler) throws Exception {
        if (logger.isDebugEnabled()) {
            // 开始时间
            long beginTime = System.currentTimeMillis();
            // 线程绑定变量（该数据只有当前请求的线程可见）
            startTimeThreadLocal.set(beginTime);
            // sun 20190405 添加对请求参数的打印
            Map paramMap = request.getParameterMap();
            logger.debug("开始计时: {}  URI: {} Params: {}", new SimpleDateFormat("hh:mm:ss.SSS")
                    .format(beginTime), request.getRequestURI(), JsonMapper.toJsonString(paramMap));
        }
        return true;
    }

    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler,
                           ModelAndView modelAndView) throws Exception {
        if (modelAndView != null) {
            logger.info("ViewName: " + modelAndView.getViewName());
        }
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response,
                                Object handler, Exception ex) throws Exception {

        // 保存日志
        LogUtils.saveLog(request, handler, ex, null);

        // 打印JVM信息。
        if (logger.isDebugEnabled()) {
            long beginTime = startTimeThreadLocal.get(); // 得到线程绑定的局部变量（开始时间）
            long endTime = System.currentTimeMillis(); // 结束时间
            logger.debug("计时结束：{}  耗时：{}  URI: {}  最大内存: {}m  已分配内存: {}m  已分配内存中的剩余空间: {}m  最大可用内存: {}m",
                    new SimpleDateFormat("hh:mm:ss.SSS").format(endTime), DateUtils.formatDateTime(endTime - beginTime),
                    request.getRequestURI(), Runtime.getRuntime().maxMemory() / 1024 / 1024, Runtime.getRuntime().totalMemory() / 1024 / 1024, Runtime.getRuntime().freeMemory() / 1024 / 1024,
                    (Runtime.getRuntime().maxMemory() - Runtime.getRuntime().totalMemory() + Runtime.getRuntime().freeMemory()) / 1024 / 1024);
            // 删除线程变量中的数据，防止内存泄漏
            startTimeThreadLocal.remove();
        }
    }
}

这其中的BaseService是否继承并不十分重要。

配置MVC的拦截器

<mvc:interceptors>
    <mvc:interceptor>
        <mvc:mapping path="${adminPath}/**" />
        <mvc:exclude-mapping path="${adminPath}/"/>
        <mvc:exclude-mapping path="${adminPath}/login"/>
        <mvc:exclude-mapping path="${adminPath}/sys/menu/tree"/>
        <mvc:exclude-mapping path="${adminPath}/sys/menu/treeData"/>
        <mvc:exclude-mapping path="${adminPath}/oa/oaNotify/self/count"/>
        <bean class="com.nevercome.tabook.modules.sys.interceptor.LogInterceptor" />
    </mvc:interceptor>
</mvc:interceptors>

5 关于MyBatis

Log4j会自动按照配置打印Mybatis的Sql语句，如果你不想打印某一个模块的Sql语句，只需要控制这个dao层的package的打印级别为DEBUG以上就可以了。比如：

com.nevercome.tabook.modules.sys.dao=WARN