Log4j架构分析与实战

#0 系列目录#

#1 Log4j简介#

Apache Log4j是当前在J2EE和J2SE开发中用得最多的日志框架(几乎所有项目都用它),因为它具有出色的性能、灵活的配置以及丰富的功能,并且在业务有特殊的要求时,可以使用自定义组件来代替框架中已有的组件来满足要求。

基本上所有的大型应用,包括我们常用的框架,比如hibernate;spring;struts等,在其内部都做了一定数量的日志信息。为什么要做这些日志信息,在系统中硬编码日志记录信息是调试系统,观察系统运行状态的一种方式。可能大部分程序员都还记得自己最开始写代码的时候,写一个方法总是出错,就喜欢使用System.out.println(“1111111”)之类的代码来查看程序的运行是否按照自己想要的方式在运行,其实这些sysout就是日志记录信息,但使用System.out.println或者System.err.println在做日志的时候有其非常大的局限性:

第一,所有的日志信息输出都是平行的。比如我不能单独的控制只输出某一个或者某几个模块里面的日志调试信息;或者我不能控制只输出某一些日志。

第二,日志信息的输出不能统一控制。比如我不能控制什么时候打印信息,什么时候不打印信息,如果我不想打印任何信息,我只能选择到所有的java文件中去注释这些日志信息。

第三,日志信息的输出方式是固定的。比如,在编码期,就只能输出到eclipse的控制台上,在tomcat环境中就只能输出到tomcat的日志文件中,我不能选择比如输出日志到数据库或者输出日志到Email中等等复杂的控制。

所以,综上所述,在编码阶段,往往需要一种统一的硬编码日志方式,来记录程序的运行状态,并且能够提供简单的方式,统一控制日志的输出粒度和输出方式。Log4J就是在这种情况下诞生的,而现在Log4J已经被广泛的采用,成为了最流行的日志框架之一。

Log4J提供了非常简单的使用方式,如果不需要深入去发现Log4J,或者需要自己去扩展Log4J,那么使用起来是非常方便的。而Log4J也非常关注性能的问题,因为在应用中大量的采用日志的方式,会带来一些反面的问题:

1,会使一段代码的篇幅增大,增加阅读的难度;

2,增加代码量,会在一定程度上降低系统运行性能;

而Log4J在性能上不断的优化,使普通的日志输出的性能甚至做到比System.out.println更快。最后,Log4J提供了非常方便的扩展方式,能让我们非常简单的自定义自己的日志输出级别,日志输出方式等。

#2 第一个日志示例#

public class Log4jTest {
    private static Logger logger = Logger.getLogger(Log4jTest.class);

    public static void main(String[] args) {
        // 从字面意思上看非常简单,我们使用了一个基础配置器,并调用其configure()方法,即配置方法完成了配置。
        BasicConfigurator.configure();
        logger.debug("my first log4j info");
    }
}

就这么简单,通过这个例子,其实我们已经演示完了Log4j的使用方式,要把Log4J加入你的应用,只需要这么几步:

  1. 导入Log4J的包;
  2. 完成Log4J的配置。在上面的应用中,我们仅仅是使用了最简单也最缺乏灵活性的BasicConfigurator来完成配置,后面我们会逐步看到更灵活的配置方式,但是配置总是需要的一个步骤。
  3. 对于每一个需要日志输出的类来说,通过Logger.getLogger方法得到一个专属于这个类的日志记录器,
  4. 使用日志记录器完成日志信息的输出;在上面的例子中,我们仅仅看到了logger的debug方法,后面会看到更多的日志记录方式。

#3 复杂一点的例子一# 上面我们看了一个使用Log4J的最简单的示例,在这个示例里面,我们只在一个类中使用标准的配置打印了一行日志信息。接下来,我们简单模拟几个常见的日志情况,来看看Log4J的一些对日志级别的控制能力。

第一个例子,我们来看看Log4J对日志级别的控制。在Log4J中,日志是可以分成不同级别的,这和我们做日志的想法其实是保持一致的。有的时候,我们记录的信息可能是非常细节的,比如读取了一个配置文件,我们需要日志这个文件的地址,可能我们要日志这个配置文件里面每一个配置项的详细信息;而有的时候,我们不需要查看配置文件里面每一个配置项的具体信息,而只想记录当前已经完成了配置文件的读取。下面我们就来模拟这样一个例子:

  • 假设我们的代码要处理一个数据库连接的示例,有一个数据库连接配置文件:db.properties
driverClass=com.mysql.jdbc.Driver
url=jdbc:mysql:///log4j
username=log4j
password=admin
  • 接下来,我们写一个代码来读取和解析这个配置文件:
package cd.itcast.log4j;
import java.io.IOException;
import java.util.Properties;
public class Configure {
    // 同样,首先得到和这个类绑定的Logger实例
    private static Logger log = Logger.getLogger(Configure.class);

    public void config() {
        log.info("using default db.properties");
         config("db.properties");
    }

    public void config(String resourceName) {
        log.info("using config file in classpath:" + resourceName);
        try {
            Properties prop = new Properties();
            prop.load(this.getClass().getClassLoader().getResourceAsStream(resourceName));
            log.debug("load properties file success");
            for (String key : prop.stringPropertyNames()) {
                String value = prop.getProperty(key);
                // doSomeConfigWorkUseKeyAndValue(key,value)
                log.debug("[properties] " + key + " : " + value);
            }
        } catch (Exception e) {
            log.error("log properties file failed", e);
        }
    }
}

在改进后的版本中,我们需要注意几个地方:

  1. 同样,我们仍然需要得到一个和该类绑定的Logger实例
  2. 我们在该类中并没有做BasicConfigurator基础设置,因为Log4J的配置是可以放在外部的,我们的类本身只需要做日志,而不需要管怎么去配置。
  3. 在该类中,我们一共使用到了三种Logger实例的方法:
    1. info:info表示概要信息记录级别,比如代码中的正在读取配置
    1. debug:debug表示很详细的信息记录级别,比如代码中的读取的配置文件内容是什么;
    1. error:error表示对错误的记录级别,这里在error方法后面,我们把可能抛出的错误作为参数也传给了方法;
  • 完成该类后,我们写一个测试来使用这个类:

package cd.itcast.log4j;
import org.apache.log4j.BasicConfigurator;
import org.junit.Test;
public class LogTest2 {

    @Test
    public void testLog2(){
        BasicConfigurator.configure();
        Configure conf=new Configure();
        conf.config();
    }
}
  • 同样,我们先使用BasicConfigurator.config()方法来完成最基本的配置,运行测试,输出:
0 [main] INFO cd.itcast.log4j.Configure  - using default db.properties
0 [main] INFO cd.itcast.log4j.Configure  - using config file in classpath:db.properties
0 [main] DEBUG cd.itcast.log4j.Configure  - load properties file success
0 [main] DEBUG cd.itcast.log4j.Configure  - [properties] driverClass : com.mysql.jdbc.Driver
0 [main] DEBUG cd.itcast.log4j.Configure  - [properties] url : jdbc:mysql:///log4j
0 [main] DEBUG cd.itcast.log4j.Configure  - [properties] password : admin
0 [main] DEBUG cd.itcast.log4j.Configure  - [properties] username : log4j

可以通过输出看到,所有的INFO和DEBUG级别的日志信息都输出来了。接下来,我们先修改代码,让代码报个错:

package cd.itcast.log4j;
import org.apache.log4j.BasicConfigurator;
import org.junit.Test;
public class LogTest2 {

    @Test
    public void testLog2(){
        BasicConfigurator.configure();
        Configure conf=new Configure();
        conf.config("aa.properties");
    }
}
  • 这里,我们故意传一个不存在的配置文件,运行测试:
0 [main] INFO cd.itcast.log4j.Configure  - using config file in classpath:aa.properties
16 [main] ERROR cd.itcast.log4j.Configure  - log properties file failed
java.lang.NullPointerException
at java.util.Properties$LineReader.readLine(Properties.java:418)
at java.util.Properties.load0(Properties.java:337)
at java.util.Properties.load(Properties.java:325)
at cd.itcast.log4j.Configure.config(Configure.java:20)

可以看到结果里面即打印出了INFO,也打印出了我们想要的ERROR级别,但下面还有错误的栈信息,这个就看你自己了,如果不想要错误栈信息,只需要打印ERROR级别日志,那么在调用Logger.error方法的时候,不要把错误作为第二个参数传入方法就行了。代码写到这里,演示了Log4J中一个非常重要的概念:日志级别。在Log4J中,内置了几种日志级别,分别是:debug;info;warn;error;和fatal;debug、info和error前面都已经见识过了,下面简单介绍下warn和fatal:

  • (1)warn代表警告级别,表示需要引起注意,可能程序没有按照预期运行等等;
  • (2)fatal代表致命级别,表示非常严重的错误;

通过这几个级别的解释,大家应该很容易能够感觉到,日志级别是有一定的顺序的,在Log4J中,日志级别的顺序定义为:debug<info<warn<error<fatal;那么这个级别到底有什么用呢?下面接着看这个例子:

  • 假如现在我的应用已经基本测试完成,在客户那里部署了,我现在不想再看到那么详细的日志输出了,我只想看到粗略的步骤即可,即我不想看到DEBUG信息了,那怎么做呢?很简单,我们只需要在代码中加入一句话:
package cd.itcast.log4j;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.junit.Test;
public class LogTest2 {

    @Test
    public void testLog2(){
        BasicConfigurator.configure();
        Logger.getRootLogger().setLevel(Level.INFO);
        Configure conf=new Configure();
        conf.config();
    }
}
  • 在加入的这一句代码中,包含着非常重要的2个内容,大家要非常注意。在讲解之前,我们先看看输出的结果:
0 [main] INFO cd.itcast.log4j.Configure  - using default db.properties
0 [main] INFO cd.itcast.log4j.Configure  - using config file in classpath:db.properties

可以看到,这次就只打印出了INFO级别的信息,而没有打印DEBUG级别了。下面我们来稍微详细的解释一下这段代码。

第一个需要注意的就是,我们在调整打印日志级别的时候,并没有修改Configure这个类里面的代码,换句话说,这再次印证了之前我们说了,控制日志级别是应用之外的事情,而不是应用本身代码控制的

第二个需要注意的是加粗的代码,从字面意义上来看,我们先通过Logger类的getRootLogger方法得到了一个Logger类实例,这个Logger类实例就是根Logger。接着,我们设置了这个根Logger的日志级别为Level.INFO,结合最后输出的日志,我们很容易想到,我们规定了最小的输出日志级别是INFO。

这句代码反应出了两个非常重要的思想,第一个思想,之前已经提到了,日志级别是有顺序的,这里就能明显看到这个顺序对我们控制应用的中的日志级别的作用,根据刚才的顺序,我们控制了最低打印级别为Level.INFO,那么应用就只会打印出大于或等于这个级别的日志信息,即info<warn<error<fatal这四个。我们可以通过让应用报错,来看看会不会打印出error:

0 [main] INFO cd.itcast.log4j.Configure  - using config file in classpath:aa.properties
0 [main] ERROR cd.itcast.log4j.Configure  - log properties file failed

仍然正常打印出ERROR。第二个思想,代表着Log4J的一个非常重要的体系结构:日志记录器(Logger)是有层次结构的;并且,这个层次结构和类的结构是保持一致的。我们把上面的示例所涉及的两个类的结构画出来:

输入图片说明

当我们在LogTest2中使用Logger.getRootLogger()方法的时候,实际上,我们得到了整个应用的根Logger对象,即图中的rootLogger;而我们在Configure类中写的:

private static Logger log = Logger.getLogger(Configure.class);

代码的真正含义是,我在cd.itcast.log4j这个Logger体系结构下创建了一个cd.itcast.log4j.Configure名字的Logger实例。这个实例的根Logger就是在LogTest2中得到的rootLogger();因为LogTest2和Configure是在同一个classLoader之下的,所以他们共享同一个RootLogger。而当我们在rootLogger上设置了日志级别,即在该rootLogger的体系之上设置了一个默认的日志级别,即Level.INFO;而我们并没有在cd.itcast.log4j.Configure绑定的Logger上设置日志级别,所以他继承了他的祖先的日志级别,即rootLogger的Level.INFO,所以,打印出来就只有大于或等于INFO的日志级别信息了。关于Logger的体系结构,后面会详细讲到,这里大家只要心理面有一个大概的印象即可。

#4 复杂一点的例子二# 上面我们演示了一个稍微复杂一点的例子,在那个例子中,我们使用了不同的日志打印级别,并且控制了打印级别,但是上面的例子仍然是对于一个类的日志控制,我们在这个例子中,来看看,控制不同模块的日志打印

  • 在上面的例子中,我们加入一个新的类,这个类放在一个额外的包中:
package cd.itcast.core;
import org.apache.log4j.Logger;
import cd.itcast.log4j.Configure;
public class LogicProcessor {
    private static Logger log=Logger.getLogger(LogicProcessor.class);

    public void init(Configure conf){
        log.info("init logic processor using conf");
    }

    public void process(){
        log.info("process some logic");
        log.debug("process some detail logic");
    }
}

在这个类中,我们创建了一个模拟某种核心处理器的类,这个类放在了cd.itcast.core包里面,然后在这个类里面使用不同的日志级别打印了一些日志。

  • 然后我们来完成一个测试:
package cd.itcast.log4j;
import org.apache.log4j.BasicConfigurator;
import org.junit.Test;
import cd.itcast.core.LogicProcessor;
public class LogTest3 {

    @Test
    public void testLog(){
        BasicConfigurator.configure();

        Configure conf=new Configure();
        conf.config();

        LogicProcessor processor=new LogicProcessor();
        processor.init(conf);
        processor.process();
    }
}

注意,这个测试我们仍然是放在cd.itcast.log包中的,这个没有任何关系。在这个测试中,我们综合使用到了之前的Configure类和新的LogicProcessor类来完成一些业务逻辑。同样,我们先简单使用BasicConfigurator.configure()完成基础设置。运行测试,输出:

0 [main] INFO cd.itcast.log4j.Configure  - using default db.properties
0 [main] INFO cd.itcast.log4j.Configure  - using config file in classpath:db.properties
15 [main] DEBUG cd.itcast.log4j.Configure  - load properties file success
31 [main] DEBUG cd.itcast.log4j.Configure  - [properties] driverClass : com.mysql.jdbc.Driver
31 [main] DEBUG cd.itcast.log4j.Configure  - [properties] url : jdbc:mysql:///log4j
31 [main] DEBUG cd.itcast.log4j.Configure  - [properties] password : admin
31 [main] DEBUG cd.itcast.log4j.Configure  - [properties] username : log4j
31 [main] INFO cd.itcast.core.LogicProcessor  - init logic processor using conf
31 [main] INFO cd.itcast.core.LogicProcessor  - process some logic
31 [main] DEBUG cd.itcast.core.LogicProcessor  - process some detail logic

观察输出,两个类里面的所有的日志都输出了,根据上一个例子,我们基本能够猜到,默认情况下,rootLogger的日志级别被设置为了Level.DEBUG。下面,我们来模拟一个场景。假如现在我们已经完成了cd.itcast.log.Configure类的详细测试,我们只想这个类做WARN级别之上的日志输出,但是现在我们还没有确定LogicProcessor是否正常运行,所以对于LogicProcessor类我们要做DEBUG级别的日志。

  • 怎么控制这个输出?其实我们根据前一个例子解释的Logger的继承的体系结构,我们能有两种方式来完成这个目的。
  • (1)设置rootLogger日志级别为DEBUG;设置cd.itcast.log4j.Configure日志级别为WARN。
  • (2)设置rootLogger日志级别为WARN;设置cd.itcast.core.LogicProcessor日志级别为DEBUG。

我们随意选择一种模式,比如第二种,那么,修改我们的代码:

import org.junit.Test;
import cd.itcast.core.LogicProcessor;
public class LogTest3 {
    @Test
    public void testLog(){
        BasicConfigurator.configure();
        Logger.getRootLogger().setLevel(Level.WARN);
        Logger.getLogger("cd.itcast.core.LogicProcessor").setLevel(Level.DEBUG);

        Configure conf=new Configure();
        conf.config();

        LogicProcessor processor=new LogicProcessor();
        processor.init(conf);
        processor.process();
    }
}

再次运行测试,输出:

0 [main] INFO cd.itcast.core.LogicProcessor  - init logic processor using conf
0 [main] INFO cd.itcast.core.LogicProcessor  - process some logic
0 [main] DEBUG cd.itcast.core.LogicProcessor  - process some detail logic

达到我们的目的。我们回过头来看看我们到底做了些什么。加了两行代码,第一行代码大家应该熟悉了,设置rootLogger的日志级别为WARN,那么在该rootLogger体系结构中的cd.itcast.log.Configure和cd.itcast.core.LogicProcessor默认日志级别都变成了WARN。接着第二行代码,我们使用Logger.getLogger()方法,传入cd.itcast.core.LogicProcessor参数,就得到了和LogicProcessor类绑定的那个Logger实例。注意这里,通过Logger.getLogger(“cd.itcast.core.LogicProcessor”)得到的Logger实例和我们在LogicProcessor类中使用Logger.getLogger(LogicProcessor.class)得到的Logger实例是一个实例。换句话说,在一个rootLogger体系结构中,绑定到同一个名字的Logger实例只会有一份。接着,我们再设置这个Logger的日志记录级别为Level.DEBUG,那么LogicProcessor绑定的Logger实例就不再继承rootLogger的日志记录级别了。所以,能正常打印。

通过这段代码,我们可以再次看到这个rootLogger的继承体系结构和继承的关系。当然,Log4J远远不止如此。

假如现在我们在cd.itcast.log包中和cd.itcast.core包中,不止一个类,换句话说,我现在想让cd.itcast.log包及其子包中的类的日志级别为WARN,而让cd.itcast.core包及其子包中的所有类的日志级别为DEBUG,又该怎么做呢?可能这种情况才是我们在现实应用当中会遇到的吧。其实非常简单,我们只需要改一句代码:

@Test
public void testLog(){
    BasicConfigurator.configure();
    Logger.getRootLogger().setLevel(Level.WARN);
    Logger.getLogger("cd.itcast.core").setLevel(Level.DEBUG);

    Configure conf=new Configure();
    conf.config();

    LogicProcessor processor=new LogicProcessor();
    processor.init(conf);
    processor.process();
}

再次运行测试,输出:

0 [main] INFO cd.itcast.core.LogicProcessor  - init logic processor using conf
0 [main] INFO cd.itcast.core.LogicProcessor  - process some logic
0 [main] DEBUG cd.itcast.core.LogicProcessor  - process some detail logic

我们这次不再得到cd.itcast.core.LogicProcessor绑定的Logger,而是得到cd.itcast.core包对应的Logger,是的,就是这样。当我们绑定cd.itcast.core.LogicProcessor对应的Logger的时候,实际上隐式的绑定了cd、cd.itcast、cd.itcast.core这三个Logger。所以,现在的rootLogger体系结构应该是这样:

输入图片说明

那么,当我设置rootLogger的日志级别为WARN,并得到cd.itcast.core绑定的Logger,设置其日志级别为DEBUG的时候,rootLogger、cd、cd.itcast、cd.itcast.log、cd.itcast.log.Configure的日志级别都是WARN,而cd.itcast.core、cd.itcast.core.LogicProcessor的日志级别为DEBUG。

通过这个示例,我们对Logger的继承体系应该有了更深入一些的了解,也可以通过这个例子可以看出,当我们对不同级别的Logger做特定的配置的时候,会非常灵活的控制我整个系统的日志输出,这是Log4J最为强大的地方之一。

如果你曾经使用过Log4j,你也许会对上面的代码感到非常奇怪,以前不是这样用Log4J的呀,也不要慌,之后就能慢慢看到平时我们使用Log4J的方式和其使用方式后面的真正含义。

#5 Log4j体系结构# 当我们在描述为系统做日志这个动作的时候,实际上描述了3个点;类似于小学语文学语法一样。做日志,其实就是在规定,在什么地方用日志记录器以什么样的格式做日志。把三个最重要的点抽取出来,即什么地方,日志记录器,什么格式。在Log4J中,就使用了三个最重要的组件来描述这三个要素,即:

Logger:日志记录器

Appender:什么地方

Layout:什么格式

##5.1 Logger的结构## 之前的示例中大家对Logger已经有了一定的认识,Logger就是最重要的,我们直接用来完成日志的工具。使用日志框架一个非常重要的目的就是让程序员能够方便的控制特定的日志的输出。要能够控制特定日志的输出,就需要创建一种特殊的结构来划分我们的日志记录器。而对于JAVA程序员来说,按照包的层次关系划分Logger是最容易想到,也最贴近我们的代码结构的

之前我们在创建Logger的时候,都是使用Logger.getLogger(Class)方法来得到一个类绑定的日志记录器的。实际上,当我们说把一个日志记录器绑定在一个类上,这种说法是不准确的,正确的说,我们仅仅是使用给定的类的全限定名为Logger取了一个名字。这里请大家注意一下,Logger都是有名字的,假如我们除开rootLogger不谈,我们可以把Logger想象成一张表里面的数据,Logger对应的名字就是其主键,当两个Logger的名字相同,这两个Logger就是同一个Logger实例。我们可以简单的通过一个实例来验证:

@Test
public void testLoggerName(){
    BasicConfigurator.configure();
    Logger log1=Logger.getLogger("a");
    Logger log2=Logger.getLogger("a");
    log1.info(log1==log2);
}

控制台打印:

0 [main] INFO a  - true;

说明Logger自身维护着每一个名字的Logger实例的引用,保证相同名字的Logger在不同地方获取到的实例是一致的,这样就允许我们在统一的代码中配置不同Logger的特性。

另外,Logger的层次结构,也是靠Logger的名字来区分的,比如:名称为java的Logger就是java.util的父Logger;java.util是java.util.Collection的父Logger;Logger的体系结构和package的结构划分类似,使用.来区分;所以我们前面才说,使用类的全限定名是最简单,也是最符合logger的体系结构的命名方式。当然,你也可能使用任何的能想到的方式去处理Logger的命名;这也是可以的。

看到这里,可能有的人会提出疑问,那既然Logger的层次结构是按照Logger的名字来创建的,那在创建Logger的时候,是否必须按照其结构来顺序创建Logger?比如:

Logger log1=Logger.getLogger(“cd”);
Logger log2=Logger.getLogger(“cd.itcast”);
Logger log3=Logger.getLogger(“cd.itcast.log”);

是否必须要按照这个顺序创建呢?不需要。在做前面的示例的时候,我们说到,大家可以认为当我们通过Logger.getLogger(“cd.itcast.log”)的时候,Log4J其实为我们创建了cd;cd.itcast和cd.itcast.log这三个Logger;其实不然,如果是这样的话,Log4J可能会产生非常多不必要的Logger。所以,真正的方式应该是,当我通过Logger.getLogger(“cd.itcast.log”)的时候,Log4J仅仅为我们创建了cd.itcast.log这个Logger;而当我们再次使用Logget.getLogger(“cd.itcast”)的时候,Log4J才会为我们创建cd.itcast这个Logger,并且Log4J会自动的去寻找这个Logger的上下级关系,并自动的把这个新创建的Logger添加到已有的Logger结构体系中

上面说到,除了rootLogger之外,其他的Logger都有名字,那么rootLogger呢?rootLogger有下面的规范:

rootLogger是没有名字的;

rootLogger是自动存在的;

rootLogger必须设置Level等级;

rootLogger没有名字,所以无法像其他的类一样,可以通过Logger.getLogger(String)得到,他只能通过Logger.getRootLogger方法得到;而我们前面使用的Logger.getLogger(Class)方法,其实相当于Logger.getLogger(Class.getName())而已;所以真正赋予Logger的是一个名字,而不是类型;

在Logger中,非常重要的一个组件,就是Logger的日志级别,即Level。关于Level的划分,使用,我们在前面的例子中已经大概了解到了,下面来看看完整的Level的定义和其在Logger体系中的继承方式,这是一个很简单的概念。

首先,在Log4J中,为我们默认的定义了7种不同的Level级别,即all<debug<info<warn<error<fatal<off;而这7中Level级别又刚好对应着Level类中的7个默认实例:Level.ALL;Level.DEBUG;Level.INFO;Level.WARN;Level.ERROR;Level.FATAL和Level.OFF。我们在之前也只看到了其中的debug到fatal这5种;这五种日志级别正好对应着Logger中的五个方法,即:

public class Logger {
    // 输出日志方法:
    public void debug(Object message);
    public void info(Object message);
    public void warn(Object message);
    public void error(Object message);
    public void fatal(Object message);
    // 输出带有错误的日志方法:
    public void debug(Object message, Throwable t);
    public void info(Object message, Throwable t);
    public void warn(Object message, Throwable t);
    public void error(Object message, Throwable t);
    public void fatal(Object message, Throwable t);
    // 更通用的输出日志方法:
    public void log(Level p, Object message);
}

为什么这里列出了11个方法,其实大家仔细看一下就知道了,最上面5个方法和中间的5个方法其实是对应的,只是中间的5个方法都带有对应的错误信息。而更下面的log方法,是允许我们直接使用Level类型来输出日志,这给了我们直接使用自定义的Level级别提供了输出日志的方式。换句话说,debug(Object message)其实就是log(Level.DEBUG,message)的简写而已。

要能输出日志,按照常规来说,每一个Logger实例都应该设置其对应的Level;但是如果这样做,会让我们控制Logger的Level非常麻烦,而Log4J借助Logger的层级关系,使用继承的方式来最大限度的减少Level的设置。这个规律我们在之前的代码中已经讲过。

一种不太常用的方式是使用Threshold方式来限制日志输出。Threshold我们可以理解为门槛,它和Level的概念完全一致,只是使用方式有一些区别,先来看代码:

@Test
public void testLogLevel2() {
    BasicConfigurator.configure();

    Logger logger = Logger.getLogger("cd.itcast");
    logger.getLoggerRepository().setThreshold(Level.WARN);
    Logger barLogger = Logger.getLogger("cd.itcast.log");

    logger.warn("logger warn");
    logger.debug("logger debug");
    barLogger.info("bar logger info");
    barLogger.debug("bar logger debug");
}

我们先创建了一个名字为cd.itcast的Logger,这次我们并没有设置其Level,而是使用logger.getLoggerRepository()方法得到了一个LoggerRepository对象。这个LoggerRepository可以理解为Logger栈,简单说,就是从当前Logger开始其下的所有的子Logger。然后,我们设置了这个栈的日志门槛,Threshold就是门槛的意思,换句话说就是最低日志输出级别为WARN,那么其下的所有的Logger的最低日志输出级别就变为了WARN。所以,这段代码执行的结果是:

0 [main] WARN cd.itcast  - logger warn

Threshold优先级>Level优先级,这里需要注意一点,Threshold优先级大于Level优先级,不等于Level就没有了意义。假如Threshold设置的级别为DEBUG,而Level设置的等级为INFO,那么最终,logger.debug还是不会输出日志。

Threshold的方式和Level一样,如果子Logger设置了自己的Threshold,则会使用自己的Threshold,如果没有设置,则继续向上查询,直到找到一个父类的Threshold或者rootLogger的level。只要父Logger的Threshold设置好了,子Logger的Level也失效了。

上面简单的介绍了Logger和Level的意义和使用方式,其实,在真正使用Log4J的时候,我们一般都不需要使用代码的方式去配置Level或者Threshold,这些配置更多的时候是使用配置文件来完成的,这个后面会详细介绍。但是,不管使用什么样的配置文件,最终也会解释成这样的配置代码,所以,理解了这些代码,再去使用配置文件,会更加清楚到底配置文件在干什么,同样,为我们自己去扩展Log4J的配置,想要自己去实现自定义的配置文件格式,提供了可能。

##5.2 Appender的结构## 使用Logger的日志记录方法,仅仅是发出了日志记录的事件,具体日志要记录到什么地方,需要Appender的支持。在Log4J中,Appender定义了日志输出的目的地。在上面所有的示例当中,我们日志输出的目的地都是控制台,在Log4j中,还有非常多的Appender可供选择,可以将日志输出到文件,网络,数据库等等,这个后面再介绍。说到这里,可能有人就已经会思考,既然Logger对象的info()等方法仅仅是发出了日志记录的事件,还需要指定输出目的地;那么我们之前的示例代码也并没有为任何一个Logger设置Appender啊?其实这很好理解,我们回顾一下之前的Level,按道理,也应该为每一个Logger指定对应的日志输出级别,但是我们也并没有这样做,正是因为Logger本身存在一个完整的体系结构,而Level能够在这个结构中自下而上的继承。同理,Appender也具有这种继承的特性。下面给出一段代码,先看看怎么使用代码的方式指定Appender:

@Test
public void testLogAppender1(){
    Logger log1=Logger.getLogger("cd");
    log1.setLevel(Level.DEBUG);
    log1.addAppender(new ConsoleAppender(new SimpleLayout()));
    Logger log2=Logger.getLogger("cd.itcast.log");
    log2.info("log2 info");
    log2.debug("log2 debug");
}

注意在这段代码中的加粗的代码。第一句代码设置了日志级别为DEBUG;第二条代码,调用了Logger的addAppender 方法添加了一个ConsoleAppender;从类的名字上看就知道这是一个把日志输出到控制台上的Appender,在创建ConsoleAppender的时候,又传入了一个SimpleLayout的实例;关于Layout下面再介绍,现在只需要关注Appender的继承特性。接下来,又创建了一个cd.itcast.log的子Logger;并且使用这个Logger输出了两条日志信息。运行测试,输出:

INFO - log2 info
DEBUG - log2 debug

请注意这个输出,很明显已经和之前的输出信息的格式完全不一样了,这里的输出格式就是由我们在cd这个Logger上面设置的ConsoleAppender+SimpleLayout所规定的。从这个例子中,我们可以看到,我们改变了cd这个Logger的Appender;他下面的子Logger自然就继承了这个Appender,输出了另外一种格式的信息。从这段代码中,我们能看出Logger的继承性,假如我们把代码修改为以下这样:

@Test
public void testLogAppender1(){
    BasicConfigurator.configure();
    Logger log1=Logger.getLogger("cd");
    log1.setLevel(Level.DEBUG);
    log1.addAppender(new ConsoleAppender(new SimpleLayout()));
    Logger log2=Logger.getLogger("cd.itcast.log");
    log2.info("log2 info");
    log2.debug("log2 debug");
}

在这段代码中,我们仅仅只是添加了BasicConfigurator来完成一个基本的配置。我们先来分析下这段代码。首先我们完成了基本的配置,从前面的测试代码中,我们可以知道,这条代码为rootLogger设置了一个DEBUG的Level;另外,现在我们知道了,这条代码肯定还为rootLogger添加了一个ConsoleAppender。然后我们创建了名字为cd的Logger,并且另外添加了一个Appender;接着又创建了名字为cd.itcast.log的Logger,最后使用这个Logger输出了两条日志信息。根据前面的Level的表现,我们猜想,当使用cd.itcast.log这个Logger做日志的时候,因为这个Logger本身是没有添加任何Appender,所以他会向上查询任何一个添加了Appender的父Logger,即找到了cd这个Logger,最后使用cd这个Logger完成日志,那么我们预计的结果是这段代码和上一段代码输出相同。

我们来运行一下这段代码,输出:

INFO - log2 info
0 [main] INFO cd.itcast.log  - log2 info
DEBUG - log2 debug
0 [main] DEBUG cd.itcast.log  - log2 debug

和我们预测的结果不一样。log2 info和log2 debug分别被输出了两次。我们观察结果,两条日志的输出都是先有一条ConsoleAppender+SimpleLayout的方式输出的然后紧跟一条使用BasicConfigurator的输出方式。那我们就能大胆的猜测了,Logger上的Appender不光能继承其父Logger上的Appender,更重要的是,他不光只继承一个,而是只要是其父Logger,其上指定的Appender都会追加到这个子Logger之上。所以,这个例子中,cd.itcast.log这个Logger不光继承了cd这个Logger上的Appender,还得到了rootLogger上的Appender;所以输出了这样的结果。在Log4J中,这个特性叫做Appender的追加性。默认情况下,所有的Logger都自动具有追加性,通过一个表来说明:

输入图片说明

但是,在某些情况下,这样做反而会引起日志输出的混乱。有些时候,我们并不希望Logger具有追加性。比如在上面这张表中,我们想让cd.itcast.log只需要继承A2和自己的A3Appender,而不想使用root上面的A1 Appender,又该怎么做呢?

其实很简单,在Logger上,都有一个setAdditivity方法,如果设置setAdditivity为false,则该logger的子类停止追加该logger之上的Appender;如果设置为true,则具有追加性。修改一下上表:

输入图片说明

再来一段代码看看是否如此:

@Test
public void testLogAppender2() throws Exception{
    BasicConfigurator.configure();
    Logger log1=Logger.getLogger("cd");
    log1.setAdditivity(false);
    log1.addAppender(new ConsoleAppender(new SimpleLayout()));

    Logger log2=Logger.getLogger("cd.itcast");
    log2.addAppender(new FileAppender(new SimpleLayout(),"a0.log"));

    Logger log3=Logger.getLogger("cd.itcast.log");
    log3.info("log2 info");
}

先来分析这段代码,在这段代码中有一些新的知识,简单理解即可。首先,我们使用BasicConfigurator.configure()方法配置了rootLogger;接着定义了名称为cd的Logger;并为其添加了一个ConsoleAppender,但是这里,我们这里设置了additivity为false,即cd和cd之后的logger都不会再添加rootLogger的Appender了。接下来,我们创建了cd.itcast这个Logger,并且为这个Logger指定了一个FileAppender。FileAppender很简单,除了同样要指定一个Layout,这个在后面介绍,第二个参数还需要指定输出日志的名称;最后,我们创建了cd.itcast.log,并使用这个Logger输出日志。按照上面的表所展示的规律,因为cd.itcast.log没有指定任何的Appender,所以向上查询。找到cd.itcast,cd.itcast.log得到其上的FileAppender,因为cd.itcast没有设置additivity,默认为true,继续向上查找,cd.itcast.log会得到cd的ConsoleAppender;但是因为cd设置了additivity为false,所以不再向上查询,最后,cd.itcast.log会向FileAppender和ConsoleAppender输出日志。

运行测试,结果:

INFO - log2 info

并且在应用下增加一个a0.log文件,内容为INFO - log2 info。符合我们的预期。

在Log4J中,一个Logger可以添加多个Appender,不管是通过继承的方式还是通过调用Logger.addAppender方法添加。只要添加到了某一个Logger之上,在这个Logger之上的任何一个可以被输出的日志都会分别输出到所有的Appender之上。

##5.3 docLayout的结构## Logger规定了输出什么日志,Appender规定了日志输出到哪里,当然,我们还会奢望,以什么样的方式输出日志。这就涉及到之前我们在观察Appender的时候创建ConsoleAppender和FileAppender都需要传入的Layout。在Log4J中,Layout对象提供了以什么样的方式格式化日志。这个对象是绑定在Appender之上的,一般在Appender创建的时候指定

下面就简单看一个最常使用的Layout:PatternLayoutPatternLayout允许使用标准的输出格式来指定格式化日志消息的样式。举个简单的例子,可能之前大家看到的使用BasicConfigurator配置的rootLogger输出的日志样式和我们使用ConsoleAppender(new SimpleLayout)创建的输出样式完全不一样。那大抵类似:

0 [main] INFO cd.itcast.core.LogicProcessor  - process some logic

那这样的日志输出样式是什么样子的呢?一个代码:

@Test
public void testPatternLayout(){
    Logger log=Logger.getLogger("cd");
    String pattern="%r [%t] %-5p %c - %m%n";
    log.addAppender(new ConsoleAppender(new PatternLayout(pattern)));
    Logger log2=Logger.getLogger("cd.itcast.log");
    log2.info("log2 info");
}

运行测试输出:

0 [main] INFO  cd.itcast.log - log2 info

符合我们的预期。注意粗体字。首先定义了一个格式化日志的模式,在这个模式中,有很多以%开头的参数,每一个特定的参数代表着一种日志的内容。比如%r代表从Log4j启动到运行这条日志的时间差,单位为毫秒;第二个参数%t代表运行该日志的线程名称;第三个参数%-5p,首先-5代表这个字符总占用5个位置,p代表日志输出级别;%c代表输出日志的Logger的名字;%m代表输出的日志内容;%n代表分行。可以看到,其实PatternLayout的使用是非常简单的,只需要了解所有内置的参数和其表示的含义,再按照想要的方式输出即可。具体日志格式化参数,请参见Properties配置文件

##5.4 三个组件的使用## 前面简单的了解了Log4J中最重要的3个组件,下面我们来看看Log4j是怎么使用这3个组件完成当我们调用logger.debug()方法能在控制台上打印出日志信息的

  1. 第一步,继承数体系上的门槛检查:首先当调用info()方法后,Log4J会立刻使用该Logger所在的体系结构中设置的门槛去检查当前日志的级别。如果级别不够,立刻作废当前日志请求。
  2. 第二步,Level级别检查:使用当前Logger上设置的或者继承的Level级别来检查当前的日志级别。如果当前日志级别不够,立刻作废当前日志请求。
  3. 第三步,创建LoggingEvent对象:当日志审核通过,Log4J就会创建一个LoggingEvent对象(即日志事件对象)。在该对象中,会保存和本次日志相关的所有参数信息,包括日志内容,日志时间等。
  4. 第四步,执行Appender:当创建完成LoggingEvent对象时候,会该对象交给当前logger上起作用的所有的Appender对象,并调用这些对象的doAppend方法来处理日志消息。
  5. 第五步,格式化日志消息:接下来,会使用每一个Appender绑定的Layout对象(如果有)来格式化日志消息。Layout对象会把LoggingEvent格式化成最终准备输出的String。
  6. 第六步,输出日志消息:当得到最终要输出的String对象之后,appender会把字符输出到最终的目标上,比如控制台或者文件。

以上步骤的相关源码,请参见Log4j输出日志

  • 三个主要组件的组成结构:

输入图片说明

  • 日志执行流程图:

输入图片说明

  • 日志类结构图:

输入图片说明

##5.5 Log4j的配置文件## 通过前面的示例,我们已经对Log4j的使用方式有了一定的了解。我们再返回去看我们第二个稍微复杂的例子。单看Configure和LogicProcessor两个类,从代码的角度来看,在这两个类中硬编码日志,是没有问题的,也是没法优化的,比如在代码中添加log.info(string),这种代码是必要的;在这种情况下,我应用中所有的类必要引入的也就只是一个Logger类,引入这个复杂性也是我们能够控制的。但是最重要的注意力,我们来思考,在真正一个应用当中,我们的测试类又该怎么表现呢?通过最开始的示例代码,我们已经知道,要正常的运行Log4J的日志功能,必须要至少对rootLogger进行相关的配,之前随着我们的代码的复杂度越来越高,我们发现,要能够控制我们的日志的输出级别,各个模块的日志输出控制,我们必须要在测试代码中加入大量的Log4J的代码;比如设定Level,Threshold,Appender,Layout,Pattern等等代码,换句话说,如果这些代码都必须硬编码到程序中,我们必须要在我们的应用启动的时候就执行这些代码,比如在WEB环境中,就要使用ServletContextListener等来初始化Log4J环境,或者在我们的桌面应用的启动过程中,使用这些代码来控制Log4J的初始化。这样做的后果是,虽然我们也能达到统一控制日志输出的目的,但是我们仍然需要使用大量的代码来控制这些内容;也没法达到一种灵活统一配置的方式,因为我们知道,在大部分的情况下,使用配置文件的方式肯定优于代码的配置方式

庆幸的是,Log4J远远不止能使用代码来完成配置,他还提供了更多更灵活的配置方式,比如我们接下来要介绍的properties和XML的配置。具体Log4j配置文件介绍,请参见Log4J配置文件详解

#6 Log4j架构分析# ##6.1 组件介绍##

  1. Logger负责供客户端代码调用,执行debug(Object msg)、info(Object msg)、warn(Object msg)、error(Object msg)等方法。

输入图片说明

Logger 继承自 Category,Logger有三个子类:

  • org.apache.log4j.spi.RootLogger。这是默认的Logger类
  • org.apache.log4j.spi.NOPLogger。这个类针对日志的输出不做任何操作,直接丢弃
  • org.apache.log4j.spi.RootCategory。此类已经不推荐使用,用RootLogger代替

Logger 一共有如下日志级别:

  • DEBUG
  • INFO
  • WARN
  • ERROR
  • FATAL

另外,还有两个特殊的日志级别:

  • ALL 所有的日志输出,不论其级别。
  • OFF 所有日志一律不输出,与ALL相反。
  1. Appender负责日志的输出,Log4j已经实现了多种不同目标的输出方式,可以向文件输出日志、向控制台输出日志、向Socket输出日志等。当前Log4j中Appender的子类实现及其层次结构如下:

输入图片说明输入图片说明

  1. Layout负责日志信息的格式化

输入图片说明

已经实现的类有:

输入图片说明输入图片说明

##6.2 执行顺序及关系## 调用Log4j输出日志时,调用各个组件的顺序如下图所示:

  1. 日志信息传入 Logger
  2. 将日志信息封装成 LoggingEvent 对象并传入 Appender
  3. 在 Appender 中调用 Filter 对日志信息进行过滤调用 Layout 对日志信息进行格式化,然后输出

输入图片说明 ##6.3 Log4j初始化## 下面分三个步骤来介绍Log4j的初始化:

  1. getLogger(String):在代码中我们以如下的代码来使用Log4j,如下:
private Logger _logger = Logger.getLogger(Hello.class);

在执行Logger.getLogger(Class)方法,在Log4j内部会执行一系列方法。其执行序列图如下所示: 输入图片说明

  1. LogManager初始化:如果是第一次调用LogManager,这时Log4j会读取配置文件并对自身初始化。其执行序列图如下: 输入图片说明

其中:

  • Hierarchy 实现了 LoggerRepository 接口。
  • RootLogger 实现了 Logger 接口。
  • DefaultRepositorySelector 实现了 RepositorySelector 接口。
  • getSystemProperty(String key, String def)) 这一步骤中获取系统变量 log4j.defaultInitOverride、log4j.configuration、log4j.configuratorClass 的值。log4j已经不推荐设置这些系统变量
  • getResource(String) 这一步骤中获取 log4j.xml、log4j.properties 配置文件。首先获取log4j.xml,然后再获取log4j.properties,如果在log4j.xml 和 log4j.properties 都获取失败的情况下会用 log4j.configuration 来代替(如果log4j.configration存在的话)。
  • selectAndConfigure 这一步骤中,如果class 为空,并且 url 指向的文件名后缀为 xml,则将class设置为“org.apache.log4j.xml.DOMConfigurator”,否则新建一个“org.apache.log4j.PropertyConfigurator”的实例。
  1. 解析配置文件:获得一个Configurator实例后,调用它的 doConfigure(Url url, LoggerRepository repository)方法传入配置文件完事路径,然后解析配置文件内容。下面以 log4j.xml 为例来介绍配置文件的解析过程: 输入图片说明

  2. 在执行 doConfigure(ParseAction action, LoggerRepository repository) 方法时,会通过获取系统的环境变量 javax.xml.parsers.DocumentBuilderFactory 获得XML的Document解析器对配置文件log4j.xml进行解析。

  3. parse(Element element)的关键代码如下。

    String tagName = null;
    Element currentElement = null;
    Node currentNode = null;
    NodeList children = element.getChildNodes();
    final int length = children.getLength();
    for (int loop = 0; loop < length; loop++) {
        currentNode = children.item(loop);
        if (currentNode.getNodeType() == Node.ELEMENT_NODE) {
            currentElement = (Element) currentNode;
            tagName = currentElement.getTagName();
            if (tagName.equals(CATEGORY_FACTORY_TAG)
                || tagName.equals(LOGGER_FACTORY_TAG)) {
                parseCategoryFactory(currentElement);
            }
        }
    }
    for (int loop = 0; loop < length; loop++) {
        currentNode = children.item(loop);
        if (currentNode.getNodeType() == Node.ELEMENT_NODE) {
            currentElement = (Element) currentNode;
            tagName = currentElement.getTagName();
            if (tagName.equals(CATEGORY) || tagName.equals(LOGGER)) {
                parseCategory(currentElement);
            } else if (tagName.equals(ROOT_TAG)) {
                parseRoot(currentElement);
            } else if (tagName.equals(RENDERER_TAG)) {
                parseRenderer(currentElement);
            } else if (tagName.equals(THROWABLE_RENDERER_TAG)) {
            if (repository instanceof ThrowableRendererSupport) {
                ThrowableRenderer tr = parseThrowableRenderer(currentElement);
                if (tr != null) {
                    ((ThrowableRendererSupport) repository)
                        .setThrowableRenderer(tr);
                }
            }
        } else if (!(tagName.equals(APPENDER_TAG)
            || tagName.equals(CATEGORY_FACTORY_TAG) || tagName
            .equals(LOGGER_FACTORY_TAG))) {
            quietParseUnrecognizedElement(repository, currentElement,
              props);
        }
    }
  • 1.获取根元素的 tagName

    1)如果 tagName 不是 log4j:configuration 并且 不是已经不推荐的 configuration,输出错误信息。

    2)如果 tagName 不是 log4j:configuration 是已经不推荐的 configuration,输出警告信息。

  • 2.获取根元素的 debug 属性

    1)如果 debug 属性的值不等于""且不等于"null",调用 LogLog.setInternalDebugging(boolean),否则输出调试信息。

  • 3.获取根元素的 reset 属性

    1)如果 reset 属性的值 不等于""且等于"true",调用 repository.resetConfiguration()。

  • 4.获取根元素的 threshold 属性

    1)如果 threshold 属性不等于""且不等于"null",调用 repository.setThreshold(String)。

  • 5.循环处理根元素的所有子元素

    1)如果子元素是 categoryFactory 或 loggerFactory,则调用内部方法 parseCategoryFactory(Element factoryElement) 处理;

  • 6.再次循环处理根元素的所有子元素。

    1)如果子元素是 category 或 logger,调用内部方法 parseCategory(Element loggerElement) 处理。

    2)如果子元素是 root,调用内部方法 parseRoot(Element rootElement) 处理。

    3)如果子元素是 renderer,调用内部方法 parseRenderer(Element rootElement) 处理。

    4)如果子元素是 throwableRenderer 并且repository instanceof ThrowableRendererSupport,调用内部方法 parseThrowableRenderer(Element rootElement) 处理返回一个ThrowableRenderer,如果没有返回null,调用((ThrowableRendererSupport) repository).setThrowableRenderer(ThrowableRenderer)。

    5)如果子元素是 appender 或者 categoryFactory 或者 loggerFactory,调用内部方法 quietParseUnrecognizedElement(Object instance, Element element, Properties props) 处理。

Log4j初始化源码分析,请参见Log4j初始化

##6.4 Log4j输出日志## Log4j输出日志分为六个步骤:全局开关控制、日志等级过滤、封装日志信息、过滤器处理、日志信息格式化、输出至文件。下面分两个环节来介绍这六个步骤是如何实现的:

  • 第一环节:预处理,当调用Log4j的方法(如:debug(String, Throwable)、info(String, Throwable))输出日志时,首先对日志信息进行预处理,其序列图如下; 输入图片说明

说明:

  1. isDisabled(int level):根据全局日志等级threshold进行判断,如果日志等级低于threshold,不输出日志。
  2. isGreaterOrEquals(Priority r):根据当前logger配置的日志等级level进行判断,如果日志等级低于当前logger配置的日志等级,不输出日志。
  3. foredLog(String fqcn Priority level, Object message, Throwable t):将日志信息封装成LoggingEvent对象
  4. callAppenders(LoggingEvent event):将LoggingEvent对象分发给所有的Appender。其实现代码如下:
    public void callAppenders(LoggingEvent event) {
        int writes = 0;

        for (Category c = this; c != null; c = c.parent) {
            // Protected against simultaneous call to addAppender,
            // removeAppender,...
            synchronized (c) {
                if (c.aai != null) {
                    writes += c.aai.appendLoopOnAppenders(event);
                }
                if (!c.additive) {
                    break;
                }
            }
        }

        if (writes == 0) {
            repository.emitNoAppenderWarning(this);
        }
    }
        public int appendLoopOnAppenders(LoggingEvent event) {
        int size = 0;
        Appender appender;

        if (appenderList != null) {
            size = appenderList.size();
            for (int i = 0; i < size; i++) {
                appender = (Appender) appenderList.elementAt(i);
                appender.doAppend(event);
            }
        }
        return size;
    }
  • 第二环节:输出日志。输出日志前还有两道工序需要处理:Filter处理和日志信息格式化。其执行序列图如下: 输入图片说明

相应的代码如下:

    public synchronized void doAppend(LoggingEvent event) {
        if (closed) {
            LogLog.error("Attempted to append to closed appender named ["
                    + name + "].");
            return;
        }

        if (!isAsSevereAsThreshold(event.getLevel())) {
            return;
        }

        Filter f = this.headFilter;

        FILTER_LOOP: while (f != null) {
            switch (f.decide(event)) {

            case Filter.DENY:
                return;
            case Filter.ACCEPT:
                break FILTER_LOOP;
            case Filter.NEUTRAL:
                f = f.getNext();
            }
        }

        this.append(event);
    }

    protected void subAppend(LoggingEvent event) {
        this.qw.write(this.layout.format(event));

        if (layout.ignoresThrowable()) {
            String[] s = event.getThrowableStrRep();
            if (s != null) {
                int len = s.length;
                for (int i = 0; i < len; i++) {
                    this.qw.write(s[i]);
                    this.qw.write(Layout.LINE_SEP);
                }
            }
        }

        if (shouldFlush(event)) {
            this.qw.flush();
        }
    }

说明:

  1. decide(LoggingEvent event):有三种返回值 DENY、ACCEPT、NEUTRAL,DENY表示丢弃当前日志信息,ACCEPT表示输出当前日志信息,NEUTRAL表示继续下一个Filter。Filter只能在XML配置文件中使用,Properties文件中不支持
  2. format(LoggingEvent event):对日志进行格式化处理
  3. write(String string):将日志信息输出至目的地(文件、数据库或网格)

Log4j输出日志源码分析,请参见Log4j输出日志

#7 Log4j性能优化#

  1. log4j已成为大型系统必不可少的一部分,log4j可以很方便的帮助我们在程序的任何位置输出所要打印的信息,便于我们对系统在调试阶段和正式运行阶段对问题分析和定位。由于日志级别的不同,对系统的性能影响也是有很大的差距,日志级别越高,性能越高

  2. log4j对系统性能的影响程度主要体现在以下几方面:

  3. 日志输出的目的地,输出到控制台的速度比输出到文件系统的速度要慢

  4. 日志输出格式不一样对性能也会有影响,如简单输出布局(SimpleLayout)比格式化输出布局(PatternLayout)输出速度要快。可以根据需要尽量采用简单输出布局格式输出日志信息。

  5. 日志级别越低输出的日志内容就越多,对系统系能影响很大

  6. 日志输出方式的不同,对系统系能也是有一定影响的,采用异步输出方式比同步输出方式性能要高

  7. 每次接收到日志输出事件就打印一条日志内容比当日志内容达到一定大小时打印系能要低

  8. 针对以上几点对系能的影响中的第4,5点,对日志配置文件做如下配置:

  9. 设置日志缓存,以及缓存大小

log4j.appender.A3.BufferedIO=true
#Buffer单位为字节,默认是8K,IO BLOCK大小默认也是8K
log4j.appender.A3.BufferSize=8192

以上配置说明,当日志内容达到8k时,才会将日志输出到日志输出目的地。

  1. 设置日志输出为异步方式
    <appender name="DRFOUT" class="org.apache.log4j.DailyRollingFileAppender">
        <param name="File" value="logs/brws.log" />
        <param name="Append" value="true" />
        <param name="DatePattern" value="yyyy_MM_dd'.'" />
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d [%t] %-5p %l %x - %m%n" />
        </layout>
    </appender>
    <appender name="ASYNCOUT" class="org.apache.log4j.AsyncAppender">
        <param name="BufferSize" value="512" />
        <appender-ref ref="DRFOUT" />
    </appender>
  • 同步情况:各线程直接获得输出流进行输出(线程间不需要同步)

  • 异步情况

  1. 各线程将日志写到缓存,继续执行下面的任务(这里是异步的)。
  2. 日志线程发现需要记日志时独占缓存(与此同时各线程等待,此时各线程是被阻塞住的),从缓存中取出日志信息,获得输出流进行输出,将缓存解锁(各线程收到提醒,可以接着写日志了)。

众所周知,磁盘IO操作、网络IO操作、JDBC操作等都是非常耗时的,日志输出的主要性能瓶颈也就是在写文件、写网络、写JDBC的时候。日志是肯定要记的,而要采用异步方式记,也就只有将这些耗时操作从主线程当中分离出去才真正的实现性能提升,也只有在线程间同步开销小于耗时操作时使用异步方式才真正有效

  1. 现在我们接着分别来看看这几种记录日志的方式:

  2. 日志记录到本地文件 同样都是写本地文件Log4j本身有一个buffer处理入库,采用异步方式并不一定能提高性能(主要是如何配置好缓存大小);而线程间的同步开销则是非常大的!因此在使用本地文件记录日志时不建议使用异步方式。

  3. 日志记录到JMS JMS本身是支持异步消息的,如果不考虑JMS消息创建的开销,也不建议使用异步方式。

  4. 日子记录到SOCKET 将日志通过Socket发送,纯网络IO操作不需要反馈,因此也不会耗时。

  5. 日志记录到数据库 众所周知JDBC是几种方式中最耗时的:网络、磁盘、数据库事务,都使JDBC操作异常的耗时,在这里采用异步方式入库倒是一个不错的选择。

  6. 日志记录到SMTP 同JDBC

  7. 异步输出日志工作原理:AsyncAppender采用的是生产者消费者的模型进行异步地将Logging Event送到对应的Appender中

  8. 生产者:外部应用了Log4j的系统的实时线程,实时将Logging Event传送进AsyncAppender里

  9. 中转:Buffer和DiscardSummary

  10. 消费者:Dispatcher线程和appenders

  11. 工作原理:

    1) Logging Event进入AsyncAppender,AsyncAppender会调用append方法,在append方法中会去把logging Event填入Buffer中,当消费能力不如生产能力时,AsyncAppender会把超出Buffer容量的Logging Event放到DiscardSummary中,作为消费速度一旦跟不上生成速度,中转buffer的溢出处理的一种方案。

    2) AsyncAppender有个线程类Dispatcher,它是一个简单的线程类,实现了Runnable接口。它是AsyncAppender的后台线程。

  12. Dispatcher所要做的工作是:

    锁定Buffer,让其他要对Buffer进行操作的线程阻塞。

    看Buffer的容量是否满了,如果满了就将Buffer中的Logging Event全部取出,并清空Buffer和DiscardSummary;如果没满则等待Buffer填满Logging Event,然后notify Disaptcher线程。

    ③ 将取出的所有Logging Event交给对应appender进行后面的日志信息推送。

以上是AsyncAppender类的两个关键点:append方法和Dispatcher类,通过这两个关键点实现了异步推送日志信息的功能,这样如果大量的Logging Event进入AsyncAppender,就可以游刃有余地处理这些日志信息了。

转载于:https://my.oschina.net/xianggao/blog/518059

  • 0
    点赞
  • 1
    收藏
    觉得还不错? 一键收藏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值