性能文章>使用perf解决JDK8U小版本升级后性能下降的问题>

使用perf解决JDK8U小版本升级后性能下降的问题原创

2407112

编者按:在升级JDK8U的小版本后(从8u74升级到8u202),遇到性能剧烈下降的问题(性能下降13倍)。该应用是一个非常简单的Web应用,且应用在JDK升级前后并无任何发布修改。通常来说JDK小版本升级都是问题修复,不影响功能和性能使用,而应用性能剧烈下降一定是JDK的内部bug。对于这样明确由JDK引起的性能问题,该如何解决?最常见的方法是通过工具分析JVM执行过程,检查函数执行的情况是否发生变化,如果找到变化,则可以深入分析哪些因素引起了变化,并进一步得到根因。笔者使用perf工具分析JVM执行时的热点函数,并对出现问题的函数进行剖析,使用函数插桩来分析函数的执行次数,发现不同版本行为差异的根源,并找到了引起问题的根因。希望读者遇到性能问题时可以参照本文使用perf工具对问题进行定位。

工欲善其事,必先利其器。程序员在定位性能瓶颈的时候,要是有一个趁手的性能调优工具,能一针见血地指出程序的性能问题,可谓事半功倍。
Linux中最常用的性能调优工具Perf(Linux系统原生提供的性能分析工具),使用perf先对应用(假设要采样的应用为JavaApp)进行采样,使用record命令,如下:
perf record java JavaApp
另外perf能按出现的百分比降序打印CPU正在执行的函数名以及调用栈,如命令:
perf report -n
可打印出:
image.png
这种结果的输出还是不直观的,Linux性能优化大师Brendan Gregg发明了火焰图(因整个图形看起来像燃烧的火焰而得名),以全局的方式来看各个函数的调用时间分布,以图形化的方式列出调用栈。
1初识火焰图
火焰图是基于perf的结果生成的图形,我们先了解一下怎么去看火焰图。以下图为例:
image.png
X轴表示被抽样到的次数。理解X轴的含义,需先了解采样数据的原理。Perf是在指定时间段内,每隔一段时间采集一次数据,被采集到的次数越多,说明该函数的执行总时间长,可能的原因有:调用次数多,或者单次执行时间长。因此,X轴的宽度不能简单的认为是运行时长。
Y轴表示调用栈。
如何从火焰图看出性能的瓶颈在哪里?最有理由怀疑的地方,顶层的“平顶”。关于perf和火焰图使用方法可以参官网http://www.brendangregg.com/FlameGraphs/cpuflamegraphs.html。下面是我们利用火焰图来定位问题的一次实战。
2火焰图定位问题的实战
2.1问题场景
问题发生的场景是客户端向服务器发起http请求,服务器返回数据给客户端(这是一个非常简单的服务交互)。我们发现使用JDK 8u74的性能要远优于JDK 8u202的性能,下表中统计了20次服务器的响应时长。
image.png

从响应时间来看,8u202相比8u74性能下降13倍之多,由于应用本身并未做任何修改,所以考虑使用火焰图来定位性能消耗的问题点。在8u74和8u202分别运行应用,并用perf的record抓取数据并生成火焰图。
2.2火焰图定位
对比两张火焰图,使用8u74时ClientHandshaker.processMessage占比为1.15%,而在8u202中这个函数占比为23.98%,很明显在ClientHandshaker.processMessage带来了性能差异。 
image.png
image.png
2.3根因定位
两者在这个ClientHandshaker.processMessage上的cpu消耗差异很大,继续分析这个函数找到根因。

void processMessage(byte handshakeType, int length) throws IOException {
    if(this.state >= handshakeType && handshakeType != 0) {
        //... 异常
    } else {
        label105:
        switch(handshakeType) {
        case 0://hello_request
            this.serverHelloRequest(new HelloRequest(this.input));
            break;
        //...
        case 2://sever_hello 
            this.serverHello(new ServerHello(this.input, length));
            break;
        case 11:///certificate 
            this.serverCertificate(new CertificateMsg(this.input));
            this.serverKey = this.session.getPeerCertificates()[0].getPublicKey();
            break;
        case 12://server_key_exchange 该消息并不是必须的,取决于协商出的key交换算法
            //...
        case 13: //certificate_request 客户端双向验证时需要
            //...
        case 14://server_hello_done
            this.serverHelloDone(new ServerHelloDone(this.input));
            break;
        case 20://finished
            this.serverFinished(new Finished(this.protocolVersion, this.input, this.cipherSuite));
        }
        if(this.state < handshakeType) {//握手状态
            this.state = handshakeType;
        }
    }
}

processMessage()主要是通过不同的信息类型进行不同的握手消息的处理。而在火焰图中可以看到,JDK8u74图中,主要消耗在函数serverFinished()和serverHello()上,而JDK8u202主要消耗在函数serverHelloDone()和serverKeyExchange()。
在介绍火焰图的时候,我们有提到,X轴的长度是映射了被采样到的次数。因此需要进一步确定消耗:函数单次执行耗时过长而成为热点,还是因为频繁调用函数导致函数耗时过长而成为热点。可通过字节码插桩(通过Instrument技术实现对函数的计数,然后编译成agent,执行应用时加载agent,具体使用Instrument的方法可以参考官方文档)查看函数serverHelloDone()的调用次数及执行时间。
JDK8u202 数据

Execute count : 253
Execute count : 258
Execute count : 649
Execute count : 661
serverHelloDone execute time [1881195 ns]
Execute count : 1223
Execute count : 1234
Execute count : 1843
Execute count : 1852
serverHelloDone execute time [1665012 ns]
Execute count : 2446
Execute count : 2456
serverHelloDone execute time [1686206 ns]

JDK8u74 数据

Execute count : 56
Execute count : 56
Execute count : 56
Execute count : 56
Execute count : 56
Execute count : 56

Execute time是取了每1000次调用的平均值,Execute count每5000ms输出一次总执行次数。很明显使用JDK8u202时在不断调用serverHelloDone,而74在调用56次后没有再调用过这个函数。
初始化握手时,serverHelloDone方法中,客户端会根据服务端返回加密套件决定加密方式,构造不同的Client Key Exchange消息;服务器如果允许重用该会话,则通过在Server Hello消息中设置相同的会话ID来应答。这样,客户端和服务器就可以利用原有会话的密钥和加密套件,不必重新协商,也就不再走serverHelloDone方法。
从现象来看, JDK8u202没有复用会话,而是建立的新的会话。
2.4水落石出
查看JDK8u 161的release notes,添加了TLS会话散列和扩展主密钥扩展支持,找到引入的一个还未修复的issue,对于带有身份验证的TLS的客户端,支持UseExtendedMasterSecret会破坏TLS-Session的恢复,导致不使用现有的TLS-Session,而执行新的Handshake。
JDK8u161之后的版本(含JDK8u161),若复用会话时不能成功恢复Session,而是创建新的会话,会造成较大性能消耗,且积压的大量的不可复用的session造成GC压力变大;如果业务场景存在不变更证书密钥,需要复用会话,且对性能有要求,可通过添加参数-Djdk.tls.useExtendedMasterSecret=false来解决这个问题。
3后记
如果遇到相关技术问题(包括不限于毕昇JDK),可以通过毕昇JDK社区求助。毕昇JDK社区每双周周二举行技术例会,同时有一个技术交流群讨论GCC、LLVM、JDK和V8等相关编译技术,感兴趣的同学可以添加如下微信小助手入群,回复Compiler入群(仅限技术交流,不允许其他目的)
image.png

点赞收藏
毕昇JDK社区

毕昇JDK是华为基于OpenJDK定制的开源版本,是一款高性能、可用于生产环境的OpenJDK发行版。

请先登录,查看1条精彩评论吧
快去登录吧,你将获得
  • 浏览更多精彩评论
  • 和开发者讨论交流,共同进步

为你推荐

【全网首发】一次想不到的 Bootstrap 类加载器带来的 Native 内存泄露分析

【全网首发】一次想不到的 Bootstrap 类加载器带来的 Native 内存泄露分析

记一次“雪花算法”造成的生产事故的排查记录

记一次“雪花算法”造成的生产事故的排查记录

【全网首发】一次疑似 JVM Native 内存泄露的问题分析

【全网首发】一次疑似 JVM Native 内存泄露的问题分析

解读JVM级别本地缓存Caffeine青出于蓝的要诀2 —— 弄清楚Caffeine的同步、异步回源方式

解读JVM级别本地缓存Caffeine青出于蓝的要诀2 —— 弄清楚Caffeine的同步、异步回源方式

单服务并发出票实践

单服务并发出票实践

刺激,线程池的一个BUG直接把CPU干到100%了。

刺激,线程池的一个BUG直接把CPU干到100%了。

12
1