开源日志框架的原理与分析

疯狂的KK

发布于 2019-12-03 14:26:10

7460

发布于 2019-12-03 14:26:10

文章被收录于专栏：Java项目实战Java项目实战

本章内容根据《分布式服务架构》整理。

日志用于记录系统中硬件，软件，系统，进程和应用运行时的信息，同时可以监控系统中发生的各种事件，我们可以用它检查发生错误的原因，找到攻击者留下的攻击痕迹，也可以用来发出警报。

按照产生的来源，日志分为系统日志，容器日志和应用日志

按照目标的不同，日志分为性能日志，安全日志等

按照级别的不同，日志分为调试日志，信息日志，警告日志，错误日志

*开源日志框架的原理分析与应用实践

*日志系统的优化和最佳实践

*大数据日志系统的原理与设计

*ELK系统的构建与使用

#JDK Logger

#Apache Commons Logging

#Apache Log4j

#Sl4j

#Logback

#Apache Log4j 2

1.1.1 JDK Logger

JDK Logger从1.4版本开始，无需集成任何类库，只用方便

package com.kk;


import java.util.logging.Logger;
import java.util.logging.ConsoleHandler;
import java.util.logging.Handler;
import java.util.logging.Level;

/**
 * @author zhaokk
 * @create 2019-11-27-21:30
 */
public class JDKLoggerDemo {


    public static Logger logger = Logger.getLogger(JDKLoggerDemo.class.toString());

    static {
        Handler consoleHandler = new ConsoleHandler();
        consoleHandler.setLevel(Level.SEVERE);
        logger.addHandler(consoleHandler);
    }


    public static void main(String[] args) {
        logger.setLevel(Level.ALL);
        logger.finest("finest log");
        logger.info("info log");
    }
}

#控制台输出
D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\bin\java.exe -agentlib:jdwp=transport=dt_socket,address=127.0.0.1:51561,suspend=y,server=n -javaagent:C:\Users\14620\.IntelliJIdea2019.1\system\captureAgent\debugger-agent.jar -Dfile.encoding=UTF-8 -classpath "D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\charsets.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\deploy.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\access-bridge-64.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\cldrdata.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\dnsns.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\jaccess.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\jfxrt.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\localedata.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\nashorn.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\sunec.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\sunjce_provider.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\sunmscapi.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\sunpkcs11.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\zipfs.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\javaws.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\jce.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\jfr.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\jfxswt.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\jsse.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\management-agent.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\plugin.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\resources.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\rt.jar;D:\project01\target\classes;D:\idea\IntelliJ IDEA 2019.1.1\lib\idea_rt.jar" com.kk.JDKLoggerDemo
Connected to the target VM, address: '127.0.0.1:51561', transport: 'socket'
十一月 27, 2019 9:38:23 下午 com.kk.JDKLoggerDemo main
信息: info log
Disconnected from the target VM, address: '127.0.0.1:51561', transport: 'socket'

Process finished with exit code 0

Level为all，所有日志都会被输出，off所有日志都不会被输出

1.1.2 Apache Commons Logging

(Jakata Commons Logging JCL)

Sl4j取代了JCL，而Logback则用来取代Log4j

引入

  <dependencies>
        <dependency>
            <groupId>commons-logging</groupId>
            <artifactId>commons-logging</artifactId>
            <version>1.1.3</version>
        </dependency>
    </dependencies>

package com.kk;


import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.junit.Test;

/**
 * @author zhaokk
 * @create 2019-11-27-21:44
 */
public class CommonsLoggingDemo {
    
         private Log log=LogFactory.getLog(CommonsLoggingDemo.class);
           
         @Test
         public  void commons(){
             log.debug("debug log...");
             log.info("info  log...");
             log.warn("warn  log...");
             log.error("error log...");
             log.fatal("fatal log...");
         }
    
}
#控制台输出
D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\bin\java.exe -agentlib:jdwp=transport=dt_socket,address=127.0.0.1:51715,suspend=y,server=n -Didea.test.cyclic.buffer.size=1048576 -javaagent:C:\Users\14620\.IntelliJIdea2019.1\system\captureAgent\debugger-agent.jar -Dfile.encoding=UTF-8 -classpath "D:\idea\IntelliJ IDEA 2019.1.1\lib\idea_rt.jar;D:\idea\IntelliJ IDEA 2019.1.1\plugins\junit\lib\junit-rt.jar;D:\idea\IntelliJ IDEA 2019.1.1\plugins\junit\lib\junit5-rt.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\charsets.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\deploy.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\access-bridge-64.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\cldrdata.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\dnsns.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\jaccess.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\jfxrt.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\localedata.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\nashorn.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\sunec.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\sunjce_provider.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\sunmscapi.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\sunpkcs11.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\ext\zipfs.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\javaws.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\jce.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\jfr.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\jfxswt.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\jsse.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\management-agent.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\plugin.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\resources.jar;D:\ProgramFiles\JavaTest\java\jdk1.8.0_141\jre\lib\rt.jar;D:\project01\target\classes;C:\Users\14620\.m2\repository\commons-logging\commons-logging\1.1.3\commons-logging-1.1.3.jar;C:\Users\14620\.m2\repository\junit\junit\4.12\junit-4.12.jar;C:\Users\14620\.m2\repository\org\hamcrest\hamcrest-core\1.3\hamcrest-core-1.3.jar" com.intellij.rt.execution.junit.JUnitStarter -ideVersion5 -junit4 com.kk.CommonsLoggingDemo,commons
Connected to the target VM, address: '127.0.0.1:51715', transport: 'socket'
十一月 27, 2019 9:50:41 下午 com.kk.CommonsLoggingDemo commons
信息: info  log...
十一月 27, 2019 9:50:41 下午 com.kk.CommonsLoggingDemo commons
警告: warn  log...
十一月 27, 2019 9:50:41 下午 com.kk.CommonsLoggingDemo commons
严重: error log...
十一月 27, 2019 9:50:41 下午 com.kk.CommonsLoggingDemo commons
严重: fatal log...
Disconnected from the target VM, address: '127.0.0.1:51715', transport: 'socket'

Process finished with exit code 0

1.1.3 Apache Log4j org.apache.log4

引入

 <dependency>
            <groupId>log4j</groupId>
            <artifactId>log4j</artifactId>
            <version>1.2.17</version>
        </dependency>

搭配log4j.properties或者log4j.xml

log4j.rootLogger=INFO,FILE,CONSOOLE

log4j.appender.FILE=org.apache.log4j.FileAppender
log4j.appender.File.file=D:\\log\\Errors.log 
log4j.appender.File.ImmediateFlush=true
log4j.appender.File.Threshold=DEBUG
log4j.appender.File.append=true
log4j.appender.File.layout=org.apache.log4j.PatternLayout
log4j.appender.File.layout.conversionPatter=%d{ABSOLUTE} %5p %c{1}:%L - %m%n


log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender 
log4j.appender.CONSOLE.Target=System.out  
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout 
log4j.appender.CONSOLE.layout.ConversionPattern=[%d{yyyy-MM-dd HH:mm:ss}] [%p] %m%n

package com.kk;

import org.apache.log4j.Logger;
import org.junit.Test;

/**
 * @author zhaokk
 * @create 2019-11-27-21:54
 */
public class Log4jDemo {


    Logger logger=Logger.getLogger(Log4jDemo.class);

     @Test
     public void  test(){
         logger.trace("trace log...");
         logger.debug("debug log...");
         logger.info("info  log...");
         logger.warn("warn  log...");
         logger.error("error log...");
         logger.fatal("fatal log...");
     }
}

Netty作为Http服务器实现的一个类似回显的服务，使用Log4j记录业务日志，压测是发现每秒可处理9000个请求，关闭日志时最多可处理28000个请求

1.1.4 Sl4j

引入

<!--sl4j-->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.25</version>
</dependency>
<!--sl4j-log4j-->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-log4j12</artifactId>
    <version>1.7.7</versi

log4j.xml

<!-- 将日志信息输出到控制台 -->
<appender name="ConsoleAppender" class="org.apache.log4j.

ConsoleAppender">

<!-- 设置日志输出的样式 -->
    <layout class="org.apache.log4j.PatternLayout">
        <!-- 设置日志输出的格式 -->
        <param name="ConversionPattern" value="[%d{yyyy-

MM-dd HH:mm:ss:SSS}] [%-5p] [method:%l]%n%m%n%n" />

</layout>
    <!--过滤器设置输出的级别-->
    <filter class="org.apache.log4j.varia.LevelRangeFilter">
        <!-- 设置日志输出的最小级别 -->
        <param name="levelMin" value="WARN" />
        <!-- 设置日志输出的最大级别 -->
        <param name="levelMax" value="ERROR" />
        <!-- 设置日志输出的xxx，默认是false -->
        <param name="AcceptOnMatch" value="true" />
    </filter>
</appender>

package com.kk;

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

/**
 * @author zhaokk
 * @create 2019-11-27-22:12
 */
public class Sl4jDemo {

    Logger logger= LoggerFactory.getLogger(Sl4jDemo.class);

    @Test
    public void test(){
        logger.trace("trace log...");
        logger.debug("debug log...");
        logger.info("info  log...");
        logger.warn("warn  log...");
        logger.error("error log...");


    }
}

1.1.5 Logback

logback分为 logback-core，logback-classic，logback-acces

logback-core是后面两个模块的基础模块，包含日志框架实现的所有基础类
logback-classic是Log4j的一个改良版本，性能有较大的提高，并实现了Sl4j的API
logback-acces与Servlet容器集成，提供了HTTP访问日志功能

引入

<!--logback-->
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.1.7</version>
</dependency>
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-core</artifactId>
    <version>1.1.7</version>
</dependency>
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-access</artifactId>
    <version>1.1.7</version>
</dependency>

使用

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false">
    <!--定义日志文件的存储地址 勿在 LogBack 的配置中使用相对路径-->
    <property name="LOG_HOME" value="/home" />
    <!-- 控制台输出 -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <!--格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg：日志消息，%n是换行符-->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
        </encoder>
    </appender>
    <!-- 按照每天生成日志文件 -->
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!--日志文件输出的文件名-->
            <FileNamePattern>${LOG_HOME}/TestWeb.log.%d{yyyy-MM-dd}.log</FileNamePattern>
            <!--日志文件保留天数-->
            <MaxHistory>30</MaxHistory>
        </rollingPolicy>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <!--格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg：日志消息，%n是换行符-->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
        </encoder>
        <!--日志文件最大的大小-->
        <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <MaxFileSize>10MB</MaxFileSize>
        </triggeringPolicy>
    </appender>

    <!-- 日志输出级别 -->
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

使用

/**
 * @author zhaokk
 * @create 2019-11-27-22:20
 */
public class LogbackDemo {

    Logger logger = LoggerFactory.getLogger(LogbackDemo.class);

    @Test
    public void test() {
        logger.trace("trace log...");
        logger.debug("debug log...");
        logger.info("info  log...");
        logger.warn("warn  log...");
        logger.error("error log...");
        
    }
}

性能提升：Logback相对于Log4j内核进行了重写与优化，一些关键执行路径上性能至少提高10倍，初始化内存加载也变小了。

#使用logback的同步记录日志大概可以达到1.5万/s的吞吐量

#关掉日志可达到5万/s的吞吐量

#用Disruptor RingBuffer 的缓冲代替BlockQueue的实现进行定制，可达到3万/s的吞吐量

1.1.6 Apache Log4j 2

Apache Log4j 2是Log4j的升级版本。可以动态的加载任何修改过的配置，过滤器更加细化

引入

<!--log4j2-->
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.5</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>2.5</version>
</dependency>

使用

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

/**
 * @author zhaokk
 * @create 2019-11-27-22:32
 */
public class Log4j2 {
    public static void main(String[] args) {
        Logger log= LogManager.getLogger(LogManager.ROOT_LOGGER_NAME);
        log.trace("trace ...");
    }
   
}

日志系统的优化与最佳实践待续...

#开发代码时要有意识的设想代码出现问题时的场景，针对场景记录关键程序的运行信息，容易定位问题

#打印日志必须包含环境信息，例如用户ID，角色，参数等

#对线上日志定期检查

#对关键业务步骤必须打点并记录耗时和结果

本文参与腾讯云自媒体分享计划，分享自微信公众号。

原始发表：2019-11-28，如有侵权请联系 cloudcommunity@tencent.com 删除

apache