一.背景说明
这次代码新增了入参解密,出参加密,然后压测过不了,接口响应时间超过公司规定了,遂排查之,然后做个记录。
二.排查过程
方式一:
打印耗时日志
1.怀疑是加解密算法太耗时,我们是采用RSA+AES的方式;所以先补日志,在代码前后打印耗时。
2.最终看日志发现在将流转换为String耗时比较多,应该是普通io的操作是阻塞的,io的read和write需要阻塞读或者写,在高并发的情况下, 响应不过来。
这种方式比较反锁,而且在修改比较多的情况,需要补大量日志,不是很方便,建议采用第二种方式。
方式二:
1.使用top命令查看cpu,内存使用情况,我们机器是6C6G,可以发现CPU没满,但是load average非常高,说明排队的进程很多,具体情况可参考:
load average是CPU的Load,它所包含的信息不是CPU的使用率状况,而是在一段时间内CPU正在处理以及等待CPU处理的进程数之和的统计信息,也就是CPU使用队列的长度的统计信息
2.所以需要打印出线程信息来分析,使用
jstack -l pid > jstack.log 如jstack -l 14 > jstack.log
3.然后使用
top -Hp pid 查出最占cpu的线程 如top -Hp 14
4.使用
printf “%x\n” pid 得到最耗时的PID需要转换成16进制,
5.将得到的16进制值在 jstack.log中搜索找到线程信息
结合我们的项目实际情况,可以从图片看到,有2个部分影响,1.大量io操作,2.oneapm,onepam是部署的全链路探针,
最终去掉探针,并优化io。
三.修复方案
1.去掉探针
2.先采用包装流,加buffer来处理,发现效果一般
3.然后使用NIO来操作流,在buffer基础上还有一定提升,最终使用NIO将流转换成String
private String getStringFromStream(ServletInputStream inputStream){
StringBuilder builder = new StringBuilder();
try(ReadableByteChannel readableByteChannel = Channels.newChannel(inputStream)) {
ByteBuffer buffer = ByteBuffer.allocate(1024);
while((readableByteChannel.read(buffer)) != -1) {
//写模式变读模式
buffer.flip();
while(buffer.hasRemaining()) {
//因为入参已经加密过了,所以不考虑中文的问题
builder.append((char)buffer.get());
}
//重置
buffer.clear();
}
} catch (Exception e) {
log.error("getStringFromStream error:"+e);
}
return builder.toString();
}
然后复测,发现load average 降下来了,压测也过了
四.结论
日常排查问题,需要熟练jdk 工具,如jstack、jmap、jstat,可以帮助我们快速排查问题,分析问题原因。