前言
自从入职得物,接触工单系统之后,我碰到一些大大小小的问题;于是做了些记录与分析,分享下问题的排查思路。
在项目在起步阶段,一般都会为了快速上线快速给业务提供服务,欠缺设计考虑。一方面是因为业务在初期阶段需求不明确,另一方面也是因为开发难以预料到后面业务发展导致以前的代码变成了后来的问题。
10月15日时,我发现系统提示CPU使用过高。如下图所示:
排查后,我发现发现占用CPU过高是Java的同一线程,通过线程的stack发现问题代码在TicketExportServiceImpl#mapTicketExportView2 的520行。
520行代码只是一个普通stream,没有特别之处,那有问题可能就是userList数据量太多,如下图:
查看数据来源,发现通过 findAll 把所有用户查出来并缓存,而所有用户总共是2w多,也不至于长时间占用CPU。
想来想去,去看看谁调用了 mapTicketExportView2 这个方法,发现外面还有一层循环。通过日志发现,外层循环的数据可达16W左右,高的高达将近60w,那么这行最高将执行60w*2w=120亿次,但方法里有两个stream,也就是240亿次循环(实际上没那么多,因为里面的stream的findFirst会短路短路)。
至此,原因找到了
为了最小限度修改保持原有逻辑,在缓存加载UserList的同时,将userList转成了userMap。
在使用到的地方都直接从map中获取,也就不存在循环嵌套的问题,即最高执行60W次循环,效果还是很显著的。但还没有根治,毕竟数据量太大,60w的数据在循环期间,仍然会占用很高CPU。
11月4日,系统再一次CPU告警,一样的排查方式,发现问题代码在DataEsUtil#nearlyThreeDayUnComplete的158行。
158行代码也是一个循环里,通过查看数据量,也仅仅是1w的数据量,这个方法也没有被循环调用,似乎不会引起占用如此高的CPU。
通过查看代码,突然间发现parallelStream的resultMap是HashMap,也就是在一个并行流里面往HashMap写数据。
线程的stack也佐证了这一点,原因已经明了。相信很多人在面试的时候也会被问到HashMap线程安全问题及一些问题后果。
很简单,直接将parallelStream改为Stream。
通过监控平台发现,线上机器内存占用偏高。不过通过监控的GC,及内存趋势来看,判断不是内存泄漏,也没有溢出报错。
通过jmap命令发现kefu里的UserInfoDto(DictDto也有同样问题)有84400个实例,高得不符合常理(用户表只有2w多数据)。
通过查看代码,ITicketUserService#findAll查询所有用户。而有两个缓存类TicketQueryDataCache、UserDataCache通过findAll查询所有用户并缓存了起来,然后目前用户数只有2w多,两个共4w达不到8w。
这两缓存都通过guava的loadingcache实现的。
通过资料及源码发现,loadingcache里是基于类LocalCache实现缓存存储,继承于ConcurrentMap,也没有使用到软引用、弱引用。就是说,GC的时候不会回收缓存。
LocalCache初始化时默认会初始化4个segment,但由于kefu参数duration的影响,一个cache是创建2个segment,总4个segment。
注:LocalCache初始化segment代码
注:工单初始化Loadingcache代码
那LocalCache是如何清理缓存的?
过期的缓存并不会主动清理,当主动调用LocalCache.cleanUp时会清理掉该Cache下所有segment,当写缓存时会清理掉当前segment。
但目前项目代码中没有地方调用cleanUp,但会超时会重新加载并清理掉当前segment,也就是12小时才会清理一次当前segment,而且马上写入。
这里比较关键的一点是,每个cache只有一个缓存的key,这个key保存了所有的缓存数据,最终的结果是,每个segment都会保存一份2W多的数据,即使清理(过期清理)了也会被马上加载。
根据以上排查,最后会把四个segment都塞一个2w的全部用户,也就是塞4*2=8w的UserInfoDto,且垃圾回收器无法回收,跟上面jmap查出来的结果相符。
去掉一个重复的cache,每次load的时候主动调用一次cleanUp。只终的结果只会有2w在缓存里。
Java问题排查的工具还是比较多的,如jmap、jstack、JProfile、Memory Analyzer、jconsole、arthas等等。常见的问题无非就CPU、内存问题,这里简单介绍几个简单常用工具来分析Java代码问题。
先通过top 查询是否Java进程占用CPU过高。
top
通过以下命令查看Java线程使用CPU情况(pid=进程号)。
top -H -p pid
当有固定线程占用CPU时,通过以下命令查看线程的stack,具体是执行那些代码(pid=进程号,tid=线程号)。
jstack -l pid |grep -A 20 "nid=0x`printf %x tid`"
当不是固定线程时占用高CPU时,可用以下命令快速查看最忙的前几线程,执行的代码(太快用上面命令可能看不到)。
jstack -l pid |egrep -A 20 "$(ps mp pid -o THREAD,tid|sort -n -k 2r|awk 'FNR<=8{printf("nid=0x%x\n",$NF)}'|paste -d"|" -s)"
可通过以下命令查看java进程堆使用情况,可通过结果观察到是老年代使用得多还是年轻代使用得多。老年代多说明可能存在大量对象被长期(缓存、静态代码)持有不释放,年轻代比较多说明可能有的代码存取大量数据。
jmap -heap pid
可通过以下命令,查看各类的实例数量及直接占用内存空间,命令结果会从高到低排序
多执行几次间隔一定时间看有没有大的变化。
如果长时间占用比较高,说明有相关类实例长期没有释放,需要看代码具体分析。
jmap -histo:live pid
如果占用比较多且不固定,需要将内存快照进行转存,通过mat进行分析。
mat好处是可以从实例的维度查看占用内存空间、从类的维度占用内存空间,及查看直接占用内存空间、间接占用内存空间(很重要,可以分析出大致的引用关系及问题代码所在类)。
jmap -dump:live,format=b,file=/home/user/heap.bin pid
一般来说可能发生内存泄漏、内存溢出。内存泄漏可通过GC与内存占用曲线大致看出来,具体问题几乎都需要通过查看代码才可发现。
正如前文提到的,在项目在起步阶段,由于快速上线快速给业务提供服务,欠缺设计思考以及需求不明确带来的性能问题时,我们可以通过以下思路看看具体是哪里的问题;当然,能做到防范于未然是最好的。
线上性能问题一般分为内存问题、线程占用CPU问题。
CPU问题又可以分为内因、外因:
内因的话死循环或者大数据量循环、大量对象快速创建、失效导致频繁GC的比较多
外因的话一般是突发的流量导致大量线程上下文切换、大量内存失效导致频繁GC比较多
内存问题也可以分为内因、外因:
内因一般会导致内存泄漏、内存溢出
一般要注意静态变量、JVM缓存、单例等等引用导致无法实例回收,不可回收对象越来越多即是内存泄漏;另一方面就是没注意数据规模导致内存溢出。
外因的话一般是突发流量,有的代码本身就会查查询很多数据,流量一叠加就导致内存溢出。
解决问题最好的办法就是没有问题
我也总结了一些在平时写代码里需要注意的点,在此给大家分享一下心得
平台在coding时,需要问自己几个问题,可以避免很多问题的发生
遇到大数据量的时候,代码会不会有问题
遇到大并发的时候,代码会不会有问题
遇到分布式的时候,代码会不会有问题
当业务发生变化的时候,代码会不会有问题,是否容易修改
当前的代码是否有共性的地方,可不可以复用
文/滕树林
得物技术
关注我们,做最潮技术人!