简介

Netty是一个简化Java NIO编程的网络框架。就像人要吃饭一样,框架也要打日志。 Netty不像大多数框架,默认支持某一种日志实现。相反,Netty本身实现了一套日志机制,但这套日志机制并不会真正去打日志。相反,Netty自身的日志机制更像一个日志包装层。

日志框架检测顺序

Netty在启动的时候,会自动去检测当前Java进程的classpath下是否已经有其它的日志框架。 检查的顺序是:

检测顺序
检测顺序

先检查是否有slf4j,如果没有则检查是否有Log4j,如果上面两个都没有,则默认使用JDK自带的日志框架JDK Logging。 JDK的Logging就不用费事去检测了,直接拿来用了,因为它是JDK自带的。

注意到虽然Netty支持Common Logging,但在Netty本文所用的4.10.Final版本的代码里,没有去检测Common Logging,即使有支持Common Logging的代码存在。

日志框架检测细节

在Netty自身的代码里面,如果需要打日志,会通过以下代码来获得一个logger,以io.netty.bootstrap.Bootstrap这个类为例,读者可以翻开这个类瞧一瞧。

private static final InternalLogger logger = InternalLoggerFactory.getInstance(Bootstrap.class);  

要知道Netty是怎么得到logger的,关键就在于这个InternalLoggerFactory类了,可以看出来,所有的logger都是通过这个工厂类产生的。 翻开InternalLoggerFactory类的代码,可以看到类中有一个静态初始化块

    private static volatile InternalLoggerFactory defaultFactory;
    static {
        final String name = InternalLoggerFactory.class.getName();
        InternalLoggerFactory f;
        try {
            f = new Slf4JLoggerFactory(true);
            f.newInstance(name).debug("Using SLF4J as the default logging framework");
            defaultFactory = f;
        } catch (Throwable t1) {
            try {
                f = new Log4JLoggerFactory();
                f.newInstance(name).debug("Using Log4J as the default logging framework");
            } catch (Throwable t2) {
                f = new JdkLoggerFactory();
                f.newInstance(name).debug("Using java.util.logging as the default logging framework");
            }
        }
        defaultFactory = f;
    }  

Javaer们都知道,类的初始化块会在类第一次被使用的时候执行。那么什么时候称之为第一次被使用呢?比如说,静态方法被调用,静态变量被访问,或者调用构造函数。 当调用InternalLoggerFactory.getInstance(Bootstrap.class)之前,上面的静态块会被调用,而Netty对于当前应用所使用的日志框架的检测,就是在这短短的20几行代码里面实现。

首先从代码整体上可以看到,一个try-catch,在catch里面又嵌套了一个try-catch,这正好体现了日志框架的检测顺序:先检测SLF4J,后检测Log4J,都没有的话,就直接使用JDK Logging

检测SLF4J

f = new Slf4JLoggerFactory(true);这里开始检测SLF4J是否存在。

public class Slf4JLoggerFactory extends InternalLoggerFactory {
    public Slf4JLoggerFactory() {
    }
    Slf4JLoggerFactory(boolean failIfNOP) {
        assert failIfNOP; // Should be always called with true.
        // SFL4J writes it error messages to System.err. Capture them so that the user does not see such a message on
        // the console during automatic detection.
        final StringBuffer buf = new StringBuffer();
        final PrintStream err = System.err;
        try {
            System.setErr(new PrintStream(new OutputStream() {
                @Override
                public void write(int b) {
                    buf.append((char) b);
                }
            }, true, "US-ASCII"));
        } catch (UnsupportedEncodingException e) {
            throw new Error(e);
        }
        try {
            if (LoggerFactory.getILoggerFactory() instanceof NOPLoggerFactory) {
                throw new NoClassDefFoundError(buf.toString());
            } else {
                err.print(buf.toString());
                err.flush();
            }
        } finally {
            System.setErr(err);
        }
    }
    @Override
    public InternalLogger newInstance(String name) {
        return new Slf4JLogger(LoggerFactory.getLogger(name));
    }
}  

在这里可以看到Slf4JLoggerFactoryInternalLoggerFactory的一个子类实现。 如果应用的classpath下存在slf4j相关的jar包,那么当slf4j的日志框架初始化的时候,如果产生了什么错误,将会通过System.err输出; 对于Netty来讲,即使slf4j初始化失败,它也不愿让用户看到错误输出,因为对netty来说,slf4j初始化失败并不代表netty不能选择其它日志框架; 所以可以从上面代码中看到,一开始先把System.err给替换掉,让err输出被重定向到一个StringBuffer,如下代码所示:

        // SFL4J writes it error messages to System.err. Capture them so that the user does not see such a message on
        // the console during automatic detection.
        final StringBuffer buf = new StringBuffer();
        final PrintStream err = System.err;
        try {
            System.setErr(new PrintStream(new OutputStream() {
                @Override
                public void write(int b) {
                    buf.append((char) b);
                }
            }, true, "US-ASCII"));
        } catch (UnsupportedEncodingException e) {
            throw new Error(e);
        }

我们已经明白上面这段代码,就是为了重定向err输出,不让用户轻易看到。接下来看这些代码:

        try {
            if (LoggerFactory.getILoggerFactory() instanceof NOPLoggerFactory) {
                throw new NoClassDefFoundError(buf.toString());
            } else {
                err.print(buf.toString());
                err.flush();
            }
        } finally {
            System.setErr(err);
        }

首先可以看到一个try-finally结构,finally块里把System.err复位了,也就是说在初始化SLF4J之后,无论发生什么事,都应该把System.err复位。 接下来看try块里面的代码:

            if (LoggerFactory.getILoggerFactory() instanceof NOPLoggerFactory) {
                throw new NoClassDefFoundError(buf.toString());
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <version>${logback.version}</version>
            <scope>runtime</scope>
        </dependency>  

如果只有slf4j,而没有logback,那么LoggerFactory.getILoggerFactory() instanceof NOPLoggerFactory就会为true,然后代码就会抛出NoClassDefFoundError。 如果连slf4j本身都没有呢?那么运行到LoggerFactory.getLoggerFactory()就已经抛出异常了,因为找不到这个LoggerFactory类。 以上便是检测SLF4J的整个过程。

检测Log4J

如果需要检测Log4J,则说明检测不到SLF4J的存在,或者是SLF4J不可以使用。 回到InternalLoggerFactory代码里:

        try {
            f = new Slf4JLoggerFactory(true);
            f.newInstance(name).debug("Using SLF4J as the default logging framework");
            defaultFactory = f;
        } catch (Throwable t1) {
            try {
                f = new Log4JLoggerFactory();
                f.newInstance(name).debug("Using Log4J as the default logging framework");
            } catch (Throwable t2) {
                f = new JdkLoggerFactory();
                f.newInstance(name).debug("Using java.util.logging as the default logging framework");
            }
        }  

Log4J的检测很简单,很直接,直接在newInstance()方法里加载org.apache.log4j.Logger;类,如果加载不到,直接抛异常,然后转而直接使用JDK Logging。

public class Log4JLoggerFactory extends InternalLoggerFactory {
    @Override
    public InternalLogger newInstance(String name) {
        return new Log4JLogger(Logger.getLogger(name));
    }
}  

兼容性

日志级别

Netty的内部日志机制也自定义了日志打印级别,像日志的layout或者appender,则没有自己定义,完全交给底层的日志框架去做。

public enum InternalLogLevel {
    /**
     * 'TRACE' log level.
     */
    TRACE,
    /**
     * 'DEBUG' log level.
     */
    DEBUG,
    /**
     * 'INFO' log level.
     */
    INFO,
    /**
     * 'WARN' log level.
     */
    WARN,
    /**
     * 'ERROR' log level.
     */
    ERROR
}  

这里会面临日志打印级别的兼容性问题,因为SLF4J,Log4J,以及JDK Logging,都有自己的日志打印级别,比如说JDK Logging,它的日志打印级别是这样的:

  • SEVERE (highest value)
  • WARNING
  • INFO
  • CONFIG
  • FINE
  • FINER
  • FINEST (lowest value)

不仅数目对不上,而且名称也没对上。Netty采用的方式是,按级别的高低来匹配,比如Netty的DEBUG将会对应到JDK的FINE,以此做到级别的对应关系和兼容性。

消息格式化

SLF4J的Logger会有这样一种打日志的方式,采用占位的方式,举个例子:、

logger.info("Hello, I m {}, I m the president of {}""Obama""America");

上面这行代码的日志输出结果是:

Hello, I m Obama, I m the president of America

可以看到,**{}**大括号是一个占位符,其内容将会被后面的参数所代替。 但Log4J和JDK Logging并不支持这种占位的日志打印方式,因此Netty又自己搞了一下,让它的InternalLogger可以以占位的方式格式化日志输出信息。 详情可以参考io.netty.util.internal.logging.MessageFormatter这个类,到这里就不再展开了。