在编写程序的过程中，发现程序运行结果与预期不符，怎么办？当然是用System.out.println()打印出执行过程中的某些变量，观察每一步的结果与代码逻辑是否符合，然后有针对性地修改代码。

代码改好了怎么办？当然是删除没有用的System.out.println()语句了。
如果改代码又改出问题怎么办？再加上System.out.println()。
反复这么搞几次，很快大家就发现使用System.out.println()非常麻烦。
怎么办？
解决方法是使用日志。
那什么是日志？日志就是Logging，它的目的是为了取代System.out.println()。
输出日志，而不是用System.out.println()，有以下几个好处：

• 可以设置输出样式，避免自己每次都写"ERROR: " + var；
• 可以设置输出级别，禁止某些级别输出。例如，只输出错误日志；
• 可以被重定向到文件，这样可以在程序运行结束后查看日志；
• 可以按包名控制日志级别，只输出某些包打的日志；
• 可以……

总之就是好处很多啦。
提到日志，我们自然会想到SLF4J和Logback与Commons Logging和Log4j这两对好基友。

Commons Logging和Log4j

和Java标准库提供的日志不同，Commons Logging是一个第三方日志库，它是由Apache创建的日志模块。
Commons Logging的特色是，它可以挂接不同的日志系统，并通过配置文件指定挂接的日志系统。默认情况下，Commons Loggin自动搜索并使用Log4j（Log4j是另一个流行的日志系统），如果没有找到Log4j，再使用JDK Logging。
Commons Logging，可以作为“日志接口”来使用。而真正的“日志实现”可以使用Log4j。

SLF4J和Logback

前面介绍了Commons Logging和Log4j这一对好基友，它们一个负责充当日志API，一个负责实现日志底层，搭配使用非常便于开发。

有的童鞋可能还听说过SLF4J和Logback。这两个东东看上去也像日志，它们又是啥？

其实SLF4J类似于Commons Logging，也是一个日志接口，而Logback类似于Log4j，是一个日志的实现。

为什么有了Commons Logging和Log4j，又会蹦出来SLF4J和Logback？这是因为Java有着非常悠久的开源历史，不但OpenJDK本身是开源的，而且我们用到的第三方库，几乎全部都是开源的。开源生态丰富的一个特定就是，同一个功能，可以找到若干种互相竞争的开源库。

因为对Commons Logging的接口不满意，有人就搞了SLF4J。因为对Log4j的性能不满意，有人就搞了Logback。

我们先来看看SLF4J对Commons Logging的接口有何改进。在Commons Logging中，我们要打印日志，有时候得这么写

int score = 99;
p.setScore(score);
log.info("Set score " + score + " for Person " + p.getName() + " ok.");

拼字符串是一个非常麻烦的事情，所以SLF4J的日志接口改进成这样了：

int score = 99;
p.setScore(score);
logger.info("Set score {} for Person {} ok.", score, p.getName());

我们靠猜也能猜出来，SLF4J的日志接口传入的是一个带占位符的字符串，用后面的变量自动替换占位符，所以看起来更加自然。

如何使用SLF4J？它的接口实际上和Commons Logging几乎一模一样：

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

class Main {
    final Logger logger = LoggerFactory.getLogger(getClass());
}

对比一下Commons Logging和SLF4J的接口：

Commons Logging	SLF4J
org.apache.commons.logging.Log	org.slf4j.Logger
org.apache.commons.logging.LogFactory	org.slf4j.LoggerFactory

不同之处就是Log变成了Logger，LogFactory变成了LoggerFactory。

从目前的趋势来看，越来越多的开源项目从Commons Logging加Log4j转向了SLF4J加Logback。
为什么越来越多的人使用SLF4J加Logback，而不用Commons Logging加Log4j呢？是驴子是马，拿出来溜溜，我们利用jmh做一下基准测试。

利用jmh测试SLF4J和Logback与Commons Logging和Log4j的性能

使用Maven搭建基准测试项目骨架

JMH官方推荐使用Maven来搭建基准测试的骨架,使用也很简单，使用如下命令来生成maven项目:

mvn archetype:generate \
          -DinteractiveMode=false \
          -DarchetypeGroupId=org.openjdk.jmh \
          -DarchetypeArtifactId=jmh-java-benchmark-archetype \
          -DgroupId=org.sample \
          -DartifactId=test \
          -Dversion=1.0

上面的maven命令使用了jmh-java-benchmark-archetype来生成java语言的基准测试骨架，如果使用其他语言可以将这个参数对应替换,所有可选参数参考 jmh ,生成的项目groupId是org.sample,artifaceId是test，执行完之后会在当前目录下生成一个test目录，切换到test目录下执行 mvn clean install 就会生成benchmarks.jar,再使用 java -jar benchmarks.jar 就可以执行基准测试了。

JMH参数配置

如果你想直接在已有maven项目中集成JMH，那也很简单,手动在POM文件中添加以下两个依赖就行了,

<dependency>
    <groupId>org.openjdk.jmh</groupId>
    <artifactId>jmh-core</artifactId>
    <version>1.19</version>
</dependency>
<dependency>
    <groupId>org.openjdk.jmh</groupId>
    <artifactId>jmh-generator-annprocess</artifactId>
    <version>1.19</version>
    <scope>provided</scope>
</dependency>

从maven archetype插件生成的pom文件来看，这个工程使用了maven-shade-plugin来将所有的依赖打包到同一个jar包中,并在Manifest文件中配置了Main-Class属性，这样就能直接通过java -jar命令来执行了，其实通过maven-assembly-plugin也可以达到同样的效果,如下所示:

<plugin>
    <artifactId>maven-assembly-plugin</artifactId>
    <version>3.1.0</version>
    <configuration>
        <descriptorRefs>
            <descriptorRef>jar-with-dependencies</descriptorRef>
        </descriptorRefs>
        <archive>
            <manifest>
                <mainClass>org.openjdk.jmh.Mainp</mainClass>
            </manifest>
        </archive>
    </configuration>
    <executions>
        <execution>
            <id>make-assembly</id> <!-- this is used for inheritance merges -->
            <phase>package</phase> <!-- bind to the packaging phase -->
            <goals>
                <goal>single</goal>
            </goals>
        </execution>
    </executions>
</plugin>

可以看到jar包的入口在 org.openjdk.jmh.Mainp 这个类，查看这个类的源码可以发现这个类会从 /META-INF/BenchmarkList 文件中读取基准测试列表。在工作中你可能经常听过别人说不要logger中使用字符串拼接来打印日志，而是使用占位符或者使用logger.isDebugEnable()语句来判断,这三种写法的性能差异到底有多大,我们就来测试一下。

本文出于演示的目的来讲解JMH的使用,直接使用了官方的例子，使用slf4j+logback的组合来打印日志,首先在POM文件中添加依赖:

<dependency>
  <groupId>org.slf4j</groupId>
  <artifactId>slf4j-api</artifactId>
  <version>1.7.7</version>
</dependency>
<dependency>
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-classic</artifactId>
  <version>1.0.11</version>
</dependency>
</pre>

在resources目录下添加logback.xml文件，如下所示:

<configuration>
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%highlight(%d{HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n)</pattern>
    </encoder>
  </appender>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder><pattern>%msg%n</pattern></encoder>
  </appender>

  <root level="INFO">
    <appender-ref ref="CONSOLE" />
  </root>
</configuration>

在另一个项目的resources目录下添加log4j2.xml文件

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
    <Properties>
        <!-- 定义日志格式 -->
        <Property name="log.pattern">%d{MM-dd HH:mm:ss.SSS} [%t] %-5level %logger{36}%n%msg%n%n</Property>
        <!-- 定义文件名变量 -->
        <Property name="file.err.filename">log/err.log</Property>
        <Property name="file.err.pattern">log/err.%i.log.gz</Property>
    </Properties>
    <!-- 定义Appender，即目的地 -->
    <Appenders>
        <!-- 定义输出到屏幕 -->
        <Console name="console" target="SYSTEM_OUT">
            <!-- 日志格式引用上面定义的log.pattern -->
            <PatternLayout pattern="${log.pattern}" />
        </Console>
        <!-- 定义输出到文件,文件名引用上面定义的file.err.filename -->
        <RollingFile name="err" bufferedIO="true" fileName="${file.err.filename}" filePattern="${file.err.pattern}">
            <PatternLayout pattern="${log.pattern}" />
            <Policies>
                <!-- 根据文件大小自动切割日志 -->
                <SizeBasedTriggeringPolicy size="1 MB" />
            </Policies>
            <!-- 保留最近10份 -->
            <DefaultRolloverStrategy max="10" />
        </RollingFile>
    </Appenders>
    <Loggers>
        <Root level="info">
            <!-- 对info级别的日志，输出到console -->
            <AppenderRef ref="console" level="info" />
            <!-- 对error级别的日志，输出到err，即上面定义的RollingFile -->
            <AppenderRef ref="err" level="error" />
        </Root>
    </Loggers>
</Configuration>

接下来就在MyBenchmark类中写测试代码了,三个方法分别对应三种不同的打印日志的写法,如下所示:

import org.openjdk.jmh.annotations.Benchmark;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class MyBenchmark {

    private static final Logger logger = LoggerFactory.getLogger(MyBenchmark.class);

    @Benchmark
    public void testVariableArguments() {

        String x = "", y = "", z = "";

        for (int i = 0; i < 100; i++) {
            x += i;
            y += i;
            z += i;
            logger.debug("Variable arguments {} {} {}", x, y, z);
        }
    }

    @Benchmark
    public void testIfDebugEnabled() {

        String x = "", y = "", z = "";

        for (int i = 0; i < 100; i++) {
            x += i; y += i; z += i;

            if (logger.isDebugEnabled())
                logger.debug("If debug enabled {} {} {}", x, y, z);
        }
    }
}

import org.openjdk.jmh.annotations.Benchmark;
import org.apache.commons.logging.Log
import org.apache.commons.logging.LogFactory

public class MyBenchmark {

    private static final Log log = LogFactory.getLog(MyBenchmark.class);

    @Benchmark
    public void testConcatenatingStrings() {
        String x = "", y = "", z = "";

        for (int i = 0; i < 100; i++) {
            x += i; y += i; z += i;

            log.debug("Concatenating strings " + x + y + z);
        }
    }
}

最后使用maven命令打包并执行:

$ mvn clean install
$ java -jar target/benchmarks.jar

最后三种不同写法的性能对比如下所示：

迭代次数	字符串拼接	占位符	isDebugEnabled
Iteration 1	57108,635 ops/s	97921,939 ops/s	104993,368 ops/s
Iteration 2	58441,293 ops/s	98036,051 ops/s	104839,216 ops/s
Iteration 3	58231,243 ops/s	97457,222 ops/s	106601,803 ops/s
Iteration 4	58538,842 ops/s	100861,562 ops/s	104643,717 ops/s
Iteration 5	57297,787 ops/s	100405,656 ops/s	104706,503 ops/s
Iteration 6	57838,298 ops/s	98912,545 ops/s	105439,939 ops/s
Iteration 7	56645,371 ops/s	100543,188 ops/s	102893,089 ops/s
Iteration 8	56569,236 ops/s	102239,005 ops/s	104730,682 ops/s
Iteration 9	57349,754 ops/s	94482,508 ops/s	103492,227 ops/s
Iteration 10	56894,075 ops/s	101405,938 ops/s	106790,525 ops/s
Average	57491,4534 ops/s	99226,5614 ops/s	104913,1069 ops/s

最后的结果也很明显了,使用isDebugEnabled性能最佳,使用字符串拼接性能最差，使用占位符性能也还不错，但是占位符的代码可读性更好，因此在项目中推荐使用占位符打印日志。