问题现象最近笔者负责测试的某算法模块机器出现大量告警，告警显示机器CPU持续偏高。算法模块是一个优化算法，本身就是一个CPU密集型应用。一开始怀疑算法可能运行正常，但这个猜测很快就被推翻了：确认是同一个算法后，算法应用只用了一颗核。告警时，一个算法进程占用了服务器机器的全部8核，显然不是正常计算造成的。定位步骤一、定位CPU问题，分析Java调用栈：1、使用top-c查看CPU占用率高的进程：，从top命令的结果来看，进程19272的CPU占用率最高，基本是确认是这个过程导致的问题。从Command栏可以看出这是算法模块程序。注意图片是在离线4C机上重现的截图。2.使用ps-mppid-oTHREAD,tid,time命令定位问题线程。ps-mp19272-oTHREAD,tid,timeUSER%CPUPRISCNTWCHANUSERSYSTEMTIDTIMEUSER191------00:36:54USER0.019-futex_--1927200:00:00USER68.819-futex_--1927300:13:18USER30.219--192740005:50USER30.219----1927500:05:50USER30.219----1927600:05:50USER30.119----1927700:05:49USER0.419-futex_--1927800:00:05USER0。019-futex_--1927900:00:00USER0.019-futex_--1928000:00:00USER0.019-futex_--1928100:00:00USER0.419-futex_--1928200:00:04USER0.319-futex_--1928300:00:03USER0.019-futex_--1928400:00:00USER0.019-futex_--1928500:00:00USER0.019-futex_--1928600:00:00USER0.019-skb_wa--1936200:00:00从结果可以看出有问题的线程主要是19273-19277。3、使用jstack查看有问题的线程堆栈信息。由于jstack使用的线程号是十六进制的，所以需要先将线程号从十进制转为十六进制。$printf"%x\n"192734b49$jstack12262|grep-A154b49"main"#1prio=5os_prio=0tid=0x00007f98c404c000nid=0x4b49runnable[0x00007f98cbc58000]java.lang.Thread.State:RUNNABLEatjava.it.util.ArrayList.util.ArrayList:840)atoptional.score.MultiSkuDcAssignmentEasyScoreCalculator.updateSolution(MultiSkuDcAssignmentEasyScoreCalculator.java:794)atoptional.score.MultiSkuDcAssignmentEasyScoreCalculator.calculateScore(MultiSkuDcAssignmentEasyScoreCalculator.java:80)atoptional.score.MultiSkuDcAssignmentEasyScoreCalculator.calculateScore(MultiSkuDcAssignmentEasyScoreCalculator.java:17)atorg.optaplanner.core.impl.score.director.easy.EasyScoreDirector.calculateScore(EasyScoreDirector.java:60)atorg.optaplanner.core.impl.score.director.AbstractScoreDirector.doAndProcessMove(AbstractScoreDirector.java:188)atorg.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.doMove（LocalSearchDecider.java:132）atorg.optaplanner.core.impl.localsearch.decider.LocalSearchDecider.decideNextStep(LocalSearchDecider.java:116)atorg.optaplanner.core.impl.localsearch.DefaultLocalSearchPhase.solve(DefaultLocalSearchPhase.java:70)atorg.optaplanner.core.impl.solver.AbstractSolver.runPhases(AbstractSolver.java:88）atorg.optaplanner.core.impl.solver.DefaultSolver.solve（DefaultSolver.java:191）atapp.DistributionCenterAssignmentApp.main（DistributionCenterAssignmentApp.java:61）“VMThread”os_prio=0tid=0x00007f98c419d000nid=0x4b4erunnable#GCtask_prio）“Parllthread0tid=0x00007f98c405e800nid=0x4b4arunnable"GCtaskthread#1(ParallelGC)"os_prio=0tid=0x00007f98c4060800nid=0x4b4brunnable"GCtaskthread#2(ParallelGC)"os_prio=0tid=0x00007f98c4062800nid=0x4b4crunnable"GCtaskthread#3(ParallelGC)"os_prio=0tid=0x00007f98c4064000nid=0x4b4drunnable"VMPeriodicTaskThread"os_prio=0tid=0x00007f98c4240800nid=0x4b56waitingoncondition可以看出，除了0x4b49线程是正常工作线程，其他都是gc线程Atthistime,itissuspectedthattheCPUisfullduetofrequentGC.我们可以使用jstat命令查看GC统计：$jstat-gcutil19272200010S0S1EOMCCSYGCYGCTFGCFGCTGCT0.000.0022.71100.0097.1691.53212219.406282809.282828.6880.000.00100.00100.0097.1691.53212219.406283809.282828.6880.000.0092.46100.0097.1691.53212219.406283812.730832.1350.000.00100.00100.0097.1691.53212219.406284812.730832.1350.000.00100.00100.0097.1691.53212219.406285815.965835.3710.000.00100.00100.0097.1691.53212219.406285815.965835.3710.000.00100.00100.0097.1691.53212219.406286819.492838.8980.000.00100.00100.0097.1691.53212219.406286819.492838.8980.000.00100.00100.0097.1691.53212219.406287822.751842.1570.000.0030.78100.0097.1691.53212219.406287825.835845.240关注以下几列：YGC：年轻代垃圾收集次数YGCT：年轻代垃圾收集次数FGC：老年代垃圾收集次数FGCT：老年代垃圾收集次数GCT：垃圾收集总时间可以看到，5次fullGC都是20s执行的，GC耗时达到了17s。1.增加启动参数显示GC详细过程。通过加入jvm参数，更快暴露GC问题，GC详细过程显示java-Xmx1024m-verbose:gc。[FullGC（人格学）1046527K->705881K（1047552K），1.8974837Secs][FullGC（Ergonomics）1046527K->706191K->706191K（1047552K）（1047552K），2.5837756SECSECSECSECSECSECS（ER）2（ER）2（ER）[ER][ER][ER][ER][ER][ER][ER][ER][ER][ER][ER][ER][ER][ER][ER][ER>(Ergonomics)1046527K->706821K(1047552K),1.9044987secs][FullGC(Ergonomics)1046527K->707130K(1047552K),2.0856625secs][FullGC(Ergonomics)1046527K->707440K(1047552K),2.6273944secs][FullGC(Ergonomics)1046527K->707755K(1047552K),2.5668877secs][FullGC(Ergonomics)1046527K->708068K(1047552K),2.6924427secs][FullGC(Ergonomics)1046527K->708384K(1047552K),3.1084132secs][FullGC(Ergonomics)1046527K->708693k（1047552k），1.9424100Secs][fullGC（ERGONOMISS）1046527K->709007K（1047552K），1.9996261Secs，1.9996261Secs]709628K(1047552K),2.8139132secs][FullGC(人体工程学)1046527K->709945K(1047552K),3.0484079s??ecs][FullGC(人体工程学)1046527K->710258K(1047552K),2.698secs]3538[FullGC(Ergonomics)1046527K->710571K(1047552K),2.1663274secs]至此，基本可以确定CPU负载高的根本原因是内存不足导致的频繁GC。虽然从上面的分析我们可以知道是频繁的GC导致了CPU被占满了，但是问题的根源还没有找到，所以也就无从谈起如何解决了。GC的直接原因是内存不足，怀疑是算法程序内存泄露。为什么会内存泄漏虽然Java语言天生就有垃圾回收机制，但这并不代表Java没有内存泄漏。一般情况下，如果一个对象在Java语言中不再使用，Java的垃圾回收机制会及时清理这些对象占用的内存。但在某些情况下，虽然有些对象不再被程序使用，但这些对象的引用仍然存在，因此垃圾回收机制无法处理它们。随着这些对象占用的内存量越来越大，最终会导致内存溢出。Java内存泄漏很难定位。下面是一些常见的内存泄漏场景：1.对象不断地在堆上创建而没有被释放。例如，不断向列表中添加对象而不清空列表。对于这类问题，通常可以在程序运行时加上JVM参数-Xmx，指定一个较小的运行堆大小，这样更容易发现这类问题。2.不是所有的静态变量。3.对大String对象调用String.intern()方法。该方法会从字符串常量池中查询当前字符串是否存在。如果不存在，则将当前字符串放入常量池。在jdk6之前，字符串常量存储在PermGen区，但是PermGen区默认比较小，对于较大的字符串调用此方法很容易引发内存溢出问题。4.打开的输入流和连接没有关闭。由于这些资源需要相应的内存维护状态，如果不关闭，这些内存是无法释放的。如何定位上面介绍了一些常见的内存泄漏场景。在实际问题中，需要确定和检查具体的代码。结合之前频繁出现的GC问题，我来解释一下定位的思路以及相关工具的使用方法。在线定位对于在线服务，如果不能开启Debug模式，可用的工具会比较少。推荐方式：使用top-c命令查询Java高内存程序的进程pid。然后使用jcmd命令获取进程中对象的计数和内存使用信息。$jcmd24600GC.class_histogram|head-n1024600:num#instances#bytesclassname----------------------------------------------1:2865351103154208[J2:143265545844960org.optaplanner.core.impl.localsearch.scope.LocalSearchMoveScope3:143265834383792org.optaplanner.core.api.score.buildin.bendablelong.BendableLong.orgScore46:1189.impl.heuristic.selector.move.generic.ChangeMove5:24196111986056[Ljava.lang.Object;6:2399845759616java.util.ArrayList结果，#instances为对象个数，#bytes为占用内存大小，单位为byte，类名就是对应的类名。第一个是Java本机类型，实际上是long类型。另外需要注意的是，结果中的类可能存在包含关系。比如一个类中包含了多个long类型的数据，那么long对应的count也会增加，所以我们需要排除一些基本类型，在我们的程序中可能会导致count增加，重点关注我们程序中的类。如果只有jcmd的结果，其实很难直接找到问题的根源。如果线下无法复现问题，我们基本上只能针对计数较多的类名跟踪变量的数据流向，重点关注新对象附近的代码逻辑。观察代码逻辑时，重点关注上述常见的内存泄漏场景。离线定位如果内存泄漏问题可以离线重现，那么定位问题的工具就更加丰富了。下面推荐的两个主要工具是VisualVM&IDEA。这里主要说一下IDEA调试定位思路：使用IDEA调试器定位内存泄漏。如果以上过程仍然不能有效分析出问题的根源，还可以使用IDEA的调试功能进行定位。配置程序的运行参数，问题正常复现后，中断程序，逐步跟踪。针对程序中需要大量运行时间的部分，我们可以使用调试暂停功能来获取内存快照。然后这里运行暂停，在debugMemory视图中可以看到哪些类在快速增加。基本上可以断定，问题的原因是两次运行中对象的new语句。定位结果经过上面的定位步骤，终于找到了问题的根源。在求解器的LocalSearch阶段，如果使用TabuSearch策略，长时间找不到更好的解，则将当前遇到的解加入禁忌列表。对应代码部分，finalListScore是一个列表，在代码第55行不断添加moveScope对象，导致内存泄漏：解决方法是在solver处限制代码中finalListScore的长度，当在添加对象之前达到上限，完全避免内存泄漏。由于问题是一个开源求解器框架：optaplanner，为了方便日后维护，按照开源项目贡献流程，将修改后的fix提交给项目即可。如何向开源项目提交PR可以参考社区文章：https://testerhome.com/topics/2114。详情参考PR链接：https://github.com/kiegroup/optaplanner/pull/726。项目维护者从代码维护的角度并没有接受这个PR，而是用了类似的修复思路最终修复了这个存在多年的bug：https://github.com/kiegroup/optaplanner/pull/763。最后，将算法模块升级到最新版本的optaplanner依赖即可解决问题。
