很多Java开发人员都知道把一个变量声明为null有助于垃圾回收(译者注:一般而言,为null的对象都会被作为垃圾处理,所以将不用的对象显式地设为Null,有利于GC收集器判定垃圾,从而提高了GC的效率。),也有部分人知道使用final定义一个内联方法能够提高性能。但是,我们也知道,如今,JVM在不断进化,很多你昨天认定的理论到了今天则不一定试用了。(译者注:因为jvm的不断优化,大多数时候,即时我们不把不用的变量声明为null,垃圾回收器也能很快判断出该对象是否应该被回收。jvm的不断优化之后,把变量设置为null这一举动可能并不会带来显著的性能提升)那么,我们如何能够知道我们写的代码是否高效呢?其实,我们不应该去猜测,而是动手去测试。
Measure, don’t guess!
就像我的朋友 Kirk Pepperdine once said说的那样 “Measure, don’t guess“. 当我们的代码出现性能问题的时候,我们总是试图做一些小的改动(很可能是随意的改动)希望能对性能有所提升。相反,我们应该建立一个稳定的性能测试环境(包括操作系统,jvm,应用服务器,数据库等),设置一些性能目标,针对这一目标不断的进行测试,直到达到你的预期。和持续测试、持续交付类似,我们也应该进行持续的性能测试。
无论如何,性能都是一个黑暗艺术,这不是这篇文章讨论的主要内容。我只是想关注微基准测试和向您展示如何在一个真是的用例(本文以日志记录为例)中使用JMH。
在日志输出中使用微基准测试
相信很多人和我一样,在使用了多个日志框架之后,肯定见过下面这些调试日志:
logger.debug("Concatenating strings " + x + y + z); logger.debug("Using variable arguments {} {} {}", x, y, z); if (logger.isDebugEnabled()) logger.debug("Using the if debug enabled {} {} {}", x, y, z);
在一般的应用中,日志输出级别都是INFO或者WARNING。即使使用了WARNING级别,上面这几断代码都可以正常输出调试信息。但是,调试日志可以却可以影响应用的表现(性能)。为了证明这一点,我们将使用微基准测试来测试以上三种代码的性能,这里使用Java微基准测试工具(JMH)。上面的三种代码分别可以概括为:使用字符串连接、使用变量参数和使用If进行debug可用检测。
JMH设置
JMH是一个用于java或者其他JVM语言的,提供构建,运行和分析(按照多种基准:纳秒,微妙、毫秒、宏)的工具。通过maven archtype我们可以很快的创建一个JMH工程。
mvn archetype:generate -DinteractiveMode=false -DarchetypeGroupId=org.openjdk.jmh \ -DarchetypeArtifactId=jmh-java-benchmark-archetype -DarchetypeVersion=1.4.1 \ -DgroupId=org.agoncal.sample.jmh -DartifactId=logging -Dversion=1.0
使用该maven原型创建出来的项目结构如下:
一个包含了JMH相关依赖和maven-shade-plugin插件的pom文件
一个使用了
@Benchmark
注解的空的MyBenchmark
文件
这个时候,虽然我们是什么都还没做,但是我们刚刚创建的微基准测试项目已经可以启动并运行了。使用maven命令打包就能生成一个benchmarks.jar
mvn clean install java -jar target/benchmarks.jar
当我们使用以上命令运行这个jar时,我们就可以在控制台上看到一些有趣的内容输出:JMH进入循环、预热JVM,执行@Benchmark
注解的空方法,并给出每秒操作的数量。
# Run progress: 30,00% complete, ETA 00:04:41 # Fork: 4 of 10 # Warmup Iteration 1: 2207650172,188 ops/s # Warmup Iteration 2: 2171077515,143 ops/s # Warmup Iteration 3: 2147266359,269 ops/s # Warmup Iteration 4: 2193541731,837 ops/s # Warmup Iteration 5: 2195724915,070 ops/s # Warmup Iteration 6: 2191867717,675 ops/s # Warmup Iteration 7: 2143952349,129 ops/s # Warmup Iteration 8: 2187759638,895 ops/s # Warmup Iteration 9: 2171283214,772 ops/s # Warmup Iteration 10: 2194607294,634 ops/s # Warmup Iteration 11: 2195047447,488 ops/s # Warmup Iteration 12: 2191714465,557 ops/s # Warmup Iteration 13: 2229074852,390 ops/s # Warmup Iteration 14: 2221881356,361 ops/s # Warmup Iteration 15: 2240789717,480 ops/s # Warmup Iteration 16: 2236822727,970 ops/s # Warmup Iteration 17: 2228958137,977 ops/s # Warmup Iteration 18: 2242267603,165 ops/s # Warmup Iteration 19: 2216594798,060 ops/s # Warmup Iteration 20: 2243117972,224 ops/s Iteration 1: 2201097704,736 ops/s Iteration 2: 2224068972,437 ops/s Iteration 3: 2243832903,895 ops/s Iteration 4: 2246595941,792 ops/s Iteration 5: 2241703372,299 ops/s Iteration 6: 2243852186,017 ops/s Iteration 7: 2221541382,551 ops/s Iteration 8: 2196835756,509 ops/s Iteration 9: 2205740069,844 ops/s Iteration 10: 2207837588,402 ops/s Iteration 11: 2192906907,559 ops/s Iteration 12: 2239234959,368 ops/s Iteration