java 日志处理[通俗易懂]

java各日志组件介绍

common-logging(同时也称JCL)

  common-logging是 apache提供的一个通用的日志接口。用户可以自由选择第三方的日志组件作为具体实现，像log4j，或者jdk自带的logging， common-logging会通过动态查找的机制，在程序运行时自动找出真正使用的日志库。当然，common-logging内部有一个Simple logger的简单实现，但是功能很弱。所以使用common-logging，通常都是配合着log4j来使用。使用它的好处就是，代码依赖是common-logging而非log4j， 避免了和具体的日志方案直接耦合，在有必要时，可以更改日志实现的第三方库。使用common-logging的常见代码：

import org.apache.commons.logging.Log;  
import org.apache.commons.logging.LogFactory;  
public class A {  
    private static Log logger = LogFactory.getLog(A.class);  
} 

动态查找原理

  Log 是一个接口声明。LogFactory 的内部会去装载具体的日志系统，并获得实现该Log 接口的实现类。LogFactory 内部装载日志系统的流程如下：

1. 寻找org.apache.commons.logging.LogFactory 属性配置。
2. 利用JDK1.3 开始提供的service 发现机制，会扫描classpah 下的META-INF/services/org.apache.commons.logging.LogFactory文件，若找到则装载里面的配置，使用里面的配置。
3. 从Classpath 里寻找commons-logging.properties ，找到则根据里面的配置加载。
4. 使用默认的配置：如果能找到Log4j 则默认使用log4j 实现，如果没有则使用JDK14Logger 实现，再没有则使用commons-logging 内部提供的SimpleLog 实现。

  从上述加载流程来看，只要引入了log4j 并在classpath 配置了log4j.xml ，则commons-logging 就会使log4j 使用正常，而代码里不需要依赖任何log4j 的代码。

slf4j

  全称为Simple Logging Facade for JAVA，java简单日志门面。类似于Apache Common-Logging，是对不同日志框架提供的一个门面封装，可以在部署的时候不修改任何配置即可接入一种日志实现方案。不同于common-logging是在运行时进行的动态绑定，它在编译时静态绑定真正的Log库。使用SLF4J时，如果你需要使用某一种日志实现，那么你必须选择正确的SLF4J的jar包的集合（各种桥接包）。使用slf4j的常见代码：

import org.slf4j.Logger;  
import org.slf4j.LoggerFactory;  
public class A {  
      private static Logger logger = LoggerFactory.getLogger(Test.class); 
}  

slf4j静态绑定原理

  SLF4J 会在编译时绑定。org.slf4j.impl.StaticLoggerBinder面实现对具体日志方案的绑定接入。任何一种基于slf4j 的实现都要有一个这个类，也就是说实现了slf4j的产商需要重新定义与这个类相同的类名与包名。如：org.slf4j.slf4j-log4j12-1.5.6: 提供对 log4j 的一种适配实现。注意：如果有任意两个实现slf4j 的包同时出现，那么就可能出现问题。

slf4j 与 common-logging 比较

  common-logging通过动态查找的机制，在程序运行时自动找出真正使用的日志库。由于它使用了ClassLoader寻找和载入底层的日志库， 导致了象OSGI这样的框架无法正常工作，因为OSGI的不同的插件使用自己的ClassLoader。 OSGI的这种机制保证了插件互相独立，然而却使Apache Common-Logging无法工作。
  slf4j在编译时静态绑定真正的Log库,因此可以在OSGI中使用。另外，SLF4J 支持参数化的log字符串，避免了之前为了减少字符串拼接的性能损耗而不得不写的if(logger.isDebugEnable())，现在你可以直接写：logger.debug(“current user is: {}”, user)。拼装消息被推迟到了它能够确定是不是要显示这条消息的时候，但是获取参数的代价并没有幸免。

Log4j

  Apache的一个开放源代码项目，通过使用Log4j，我们可以控制日志信息输送的目的地是控制台、文件、GUI组件、甚至是套接口服务 器、NT的事件记录器、UNIX Syslog守护进程等；用户也可以控制每一条日志的输出格式；通过定义每一条日志信息的级别，用户能够更加细致地控制日志的生成过程。这些可以通过一个 配置文件来灵活地进行配置，而不需要修改程序代码。

LogBack

  Logback是由log4j创始人设计的又一个开源日记组件。logback当前分成三个模块：logback-core,logback- classic和logback-access。logback-core是其它两个模块的基础模块。logback-classic是log4j的一个 改良版本。此外logback-classic完整实现SLF4J API使你可以很方便地更换成其它日记系统如log4j或JDK14 Logging。logback-access访问模块与Servlet容器集成提供通过Http来访问日记的功能。

项目里如何实用

  跟 JCL 一样，SLF4J 也是只提供 log 接口，具体的实现是在打包应用程序时所放入的绑定器（名字为 slf4j-XXX-version.jar）来决定，XXX 可以是 log4j12, jdk14, jcl, nop 等，他们实现了跟具体日志工具（比如 log4j）的绑定及代理工作。举个例子：如果一个程序希望用 log4j 日志工具，那么程序只需针对 slf4j-api 接口编程，然后在打包时再放入 slf4j-log4j12-version.jar 和 log4j.jar 就可以了。
  假如你正在开发应用程序所调用的组件当中已经使用了 JCL 的，还有一些组建可能直接调用了 java.util.logging（JUL），这时你需要一个桥接器（名字为 XXX-over-slf4j.jar）把他们的日志输出重定向到 SLF4J，所谓的桥接器就是一个假的日志实现工具，比如当你把 jcl-over-slf4j.jar 放到 CLASS_PATH 时，即使某个组件原本是通过 JCL 输出日志的，现在却会被 jcl-over-slf4j “骗到”SLF4J 里，然后 SLF4J 又会根据绑定器把日志交给具体的日志实现工具。过程如下:

jcl -- jcl-over-slf4j.jar --- (redirect) ---> SLF4j ---> slf4j-log4j12-version.jar ---> log4j.jar ---> 输出日志

  看到上面的流程图可能会发现一个有趣的问题，假如在 CLASS_PATH 里同时放置 log4j-over-slf4j.jar 和 slf4j-log4j12-version.jar 会发生什么情况呢？没错，日志会被踢来踢去，最终进入死循环。所以使用SLF4J 的比较典型搭配就是把 slf4j-api、JCL 桥接器、java.util.logging（JUL）桥接器、log4j 绑定器、log4j 这5个 jar 放置在 class-path里。
  在引入jul-to-slf4j-version.jar后，发现jul的日志并没有通过slf4j输出到指定的地方，这是由于从java.util.logging（JUL）迁移到slf4j——jvm自己的类不允许随便替换，而jcl-over-sl4j.jar里重写了部分JCL的代码。解决办法是在启动类里（Web项目可以新建一个Listener）。示例代码如下：

import javax.servlet.ServletContextEvent;

import org.slf4j.bridge.SLF4JBridgeHandler;
import org.springframework.web.context.ContextLoaderListener;

public class SystemListener extends ContextLoaderListener {

    @Override
    public void contextInitialized(ServletContextEvent event) {
        super.contextInitialized(event);
        /******** jul to slf4j *********/
        SLF4JBridgeHandler.install();
    }

    @Override
    public void contextDestroyed(ServletContextEvent event) {
        super.contextDestroyed(event);
        /******** jul to slf4j *********/
        SLF4JBridgeHandler.uninstall();
    }

}

LogBack日志使用详解

概述

  Logback建立于三个主要类之上：日志记录器(Logger)，输出端(Appender)和日志格式化器(Layout)。这三种组件协同工作，使开发者可以按照消息类型和级别来记录消息，还可以在程序运行期内控制消息的输出格式和输出目的地。

• 日志记录器(Logger)：控制要输出哪些日志记录语句，对日志信息进行级别限制。
• 输出端(Appender)：指定了日志将打印到控制台还是文件中。
• 日志格式化器(Layout)：控制日志信息的显示格式。

日志记录器Logger

在logback中只有一个日志记录器Logger，继承自org.slf4j.Logger且是final的。

public final class Logger implements org.slf4j.Logger, LocationAwareLogger,
AppenderAttachable<ILoggingEvent>, Serializable {
}

输出端Appender

Logback提供了非常丰富的输出端Appender。

输出端Appender

其中，常用的Appender有以下几个：

• ConsoleAppender：打印日志信息到控制台，相当于System.out或者System.err。
• FileAppender：打印日志信息到文件中。
• RollingFileAppender：根据RollingPolicy和TriggeringPolicy将日志打到相应的文件中。
  RollingFileAppender有两个与之互动的重要子组件。第一个是RollingPolicy，负责滚动。第二个是TriggeringPolicy，决定是否以及何时进行滚动。所以，RollingPolicy负责“什么”， TriggeringPolicy负责“何时”。 要想RollingFileAppender起作用，必须同时设置RollingPolicy和TriggeringPolicy。不过，如果RollingPolicy也实现TriggeringPolicy接口，那么只需要设置RollingPolicy。让我们来看看这些策略都有哪些吧？
  
  

  RollingFileAppender可以配置的策略

  其中，TimeBasedRollingPolicy比较特殊，它同时继承了RollingPolicy和TriggerPolicy。即配置它一个也可以的。

日志格式化器Layout

其结构如下所示：

LogBack Layout 类图

logback配置

Logback可以通过编程式配置，或用XML格式的配置文件进行配置。Logback采取下面的步骤进行自我配置：

1. 尝试在classpath下查找文件logback-test.xml；
2. 如果文件不存在，则查找文件logback.xml；
3. 如果两个文件都不存在，logback用BasicConfigurator自动对自己进行配置，这会导致记录输出到控制台。

配置文件的例子文件如下：

<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
    <!-- 控制台输出日志 -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{60} - %msg%n</pattern>
        </layout>
    </appender>
    <!-- 文件输出日志 (文件大小策略进行文件输出，超过指定大小对文件备份) -->
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>${logCatolog}</File>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <FileNamePattern>${logCatolog}.%d{yyMMdd}</FileNamePattern>
            <!-- keep 60 days worth of history -->
            <MaxHistory>60</MaxHistory>
        </rollingPolicy>
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</Pattern>
        </layout>
    </appender>
     
    <root level="ERROR">
        <appender-ref ref="STDOUT" />
        <appender-ref ref="FILE" />
    </root>
    <!--这里指定logger name 是为jmx设置日志级别做铺垫 -->
    <logger name="com.pptv">
        <level value="DEBUG" />
    </logger>
 
    <!--mybatis -->
    <logger name="jdbc.sqltiming" level="INFO" />
</configuration>

LogBack注意点：

• log日志有相应的级别，从小到大分别为：trace<debug<info<warm<error；配置了高级别的后低级别的日志将不输出。
• logger的选择是与java包的命名空间相关的。优先选择最近的命令空间的logger。通过name进行配置。
• root是默认的logger，当找不到对应的logger的时候，会以root配置的logger进行输出，并且root配置的appender会被其它logger继承。

SLF4J MDC的使用

  在分布式系统中，各种无关日志穿行其中，导致我们可能无法直接定位整个操作流程。因此，我们可能需要对某个请求的操作流程进行归类标记，或者对某个用户的操作进行归类。MDC ( Mapped Diagnostic Contexts )，顾名思义，其目的是为了便于我们诊断线上问题而出现的方法工具类。MDC的使用很简单，首先需要往MDC里put一个key与value，然后在logback.xml通过%X{key}取出相应的值便可以。比如下面便是一个例子：

• 在业务代码里调用MDC类的put方法，往里扔一个有意义的值或者一个随机值。示例如下：

import java.util.UUID;
import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;  

public class Test {

    private static Logger logger = LoggerFactory.getLogger(Test.class);
    
    private static ThreadPoolExecutor pool;
    static{
        pool =  new ThreadPoolExecutor(5, 10,
                60L, TimeUnit.SECONDS,
                new ArrayBlockingQueue<Runnable>(100));
    }

    public static void main(String[] args) {
        for(int i=0; i<20; i++){
            pool.submit(new Runnable(){

                public void run() {
                    MDC.put("REQUEST_ID", UUID.randomUUID().toString().replace("-", ""));
                    logger.info("this is test message");
                    MDC.remove("REQUEST_ID");
                }
                
            });
        }
        

    }
}

• 在 logback.xml里通过%X{} 取出MDC里put进去的key，代码如下：

    <appender name="FILE"
        class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>D:\\logs\\sports\\log.log</File>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <FileNamePattern>D:\\logs\\sports\\log.log.%d{yyMMdd}</FileNamePattern>
            <!-- keep 60 days worth of history -->
            <MaxHistory>60</MaxHistory>
        </rollingPolicy>
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} %X{REQUEST_ID} - %msg%n</Pattern>
        </layout>
    </appender>

MDC的实现原理

  MDC内部通过InheritableThreadLocal来实现put方法线程安全。通过InheritableThreadLocal类子线程会继承父线程(Thread类)的inheritableThreadLocals变量指向的ThreadLocalMap里值的引用。MDC通过写时复制来避免父子线程间传入的mdc值之间产生影响。具体代码如下：

package ch.qos.logback.classic.util;

public final class LogbackMDCAdapter implements MDCAdapter {
final InheritableThreadLocal<Map<String, String>> copyOnInheritThreadLocal = new InheritableThreadLocal<Map<String, String>>();

//往copyOnInheritThreadLocal里的map放值
  public void put(String key, String val) throws IllegalArgumentException {
//key不能为空
    if (key == null) {
      throw new IllegalArgumentException("key cannot be null");
    }
//通过copyOnInheritThreadLocal 得到map对象
    Map<String, String> oldMap = copyOnInheritThreadLocal.get();
//将标识为设置为写
    Integer lastOp = getAndSetLastOperation(WRITE_OPERATION);
//第一次读或者在写之前有读操作，都会新创建一个新的map对象，重复创建是为了避免当前线程创建的子线程的值受当前线程的影响。
    if (wasLastOpReadOrNull(lastOp) || oldMap == null) {
      Map<String, String> newMap = duplicateAndInsertNewMap(oldMap);
      newMap.put(key, val);
    } else {
      oldMap.put(key, val);
    }
  }

//会新创建一个新的map对象
  private Map<String, String> duplicateAndInsertNewMap(Map<String, String> oldMap) {
    Map<String, String> newMap = Collections.synchronizedMap(new HashMap<String, String>());
    if (oldMap != null) {
        // we don't want the parent thread modifying oldMap while we are
        // iterating over it
        synchronized (oldMap) {
          newMap.putAll(oldMap);
        }
    }
//新建的值会设置到copyOnInheritThreadLocal里
    copyOnInheritThreadLocal.set(newMap);
    return newMap;
  }

}