Skip to content

fastjson heap oom

landon edited this page Sep 14, 2018 · 1 revision

FastJson与一起堆内存溢出'血案'

现象

  • QA同学反映登录不上服务器

排查问题1--日志级别

  • 查看log,发现玩家登录的时候抛出了一个java.lang.OutOfMemoryError
  • 大概代码是向Redis序列化一个PlayerMirror镜像数据,但是在JSON.toJSONString的时候出现了错误.比较清晰,即序列化的时候expandCapacity,内存不足
  • 又看了一下日志,有好几个OutOfMemoryError,都是类似于用fastjson序列化PlayerMirror报的错误
  • 有仔细看了一下server目录,发现了几个.hprof,说明确实发生了堆内存溢出,因为启动参数增加了'-XX:+HeapDumpOnOutOfMemoryError'
 at java.lang.OutOfMemoryError.<init>()V (OutOfMemoryError.java:48)
  at com.alibaba.fastjson.serializer.SerializeWriter.expandCapacity(I)V (SerializeWriter.java:249)
-rw-------  1 xx xx 2043416350 Nov 24 11:37 java_pid8068.hprof
-rw-------  1 xx xx 2028797313 Nov 24 11:17 java_pid4671.hprof
-rw-------  1 xx xx 1477222612 Nov 23 23:25 java_pid31563.hprof

排查问题2--JVM命令级别

  • 使用了jvm命令初步排查一下问题
    • jstat -gcutil pid
    • jstat -gc pid
    • jmap -histo pid
    • jmap -heap pid
  • jstat看到老年代基本已经满了
  • jmap看到排名前两位的分别是Object[]和char[]
 num     #instances         #bytes  class name
----------------------------------------------
   1:        146219      741203672  [Ljava.lang.Object;
   2:       2842356      639498168  [C

排查问题3--专业工具级别

  • 因为了hprof,所以只需要用专业的内存分析工具mat即可
  • mat#Open Heap Dump,载入后直接出来一个Getting Started Wizard#Leak Suspects Report,即内存泄露的报告,选择finish
  • 两个怀疑的问题
    • 其中有一个JSONArray的实例就占用了大约700M内存
    • 另外一个是线程的local Variables占用了500M内存

  • 点开问题1详情
    • 发现这个JSONArray是配置类PersonalityStrengthenConfig#cost字段
    • 仔细看一下这个JSONArray#list#elementData的数组长度是可怕的183842095

  • 点开问题2详情
    • 第一张图可以看到,fastjson内部的SerializeWriter中中buf#char[]长度竟然是可怕的262012306
    • 而第二种图的堆栈信息可以看到是在序列化PersonalityStrengthenConfig抛出的内存溢出

  • 结合两个问题,比较能容易的想到答案
    • PersonalityStrengthenConfig中的cost字段(JSONArray)占用了大量的内存
    • 而玩家下线或者上线的时候要序列化一部分数据到redis,其中就包括这个PersonalityStrengthenConfig,所以也要序列化这个超级大的cost,而序列化要申请空间,所以就内存溢出了

分析问题1--观察数据

  • 为什么数据配置类PersonalityStrengthenConfig会被序列化呢
    • 因为玩家下线的时候需要序列化一个玩家镜像数据到redis
    • Player->Hero->HeroPersonality->getConfig(PersonalityStrengthenConfig)
    • HeroPersonality有一个get方法,而做序列化的这个同学忘记加了SerializerFeature.IgnoreNonFieldGetter这个参数,所以导致getConfig中的这个config对象被序列化进去了
    • 修改完毕代码后,所有的问题都没有了
  • 需要确认一下:PersonalityStrengthenConfig#cost这个JsonArray为什么占这么大空间,能看一下里面都是什么?
    • 在mat中怀疑的第一个怀疑报告中点击PersonalityStrengthenConfig@0x8140c468对象,左侧Inspector页面有一个Attributes,找到cost右键->List Objects->with outgoing references
    • 从下图可以看到,这个JSONAray内部出了第一个元素是一个正常的JSONObject外,其他的全部为null
    • 当然你可以从第二个怀疑报告中将SerializeWriter中的buf#char[]数据拷贝出来->单击->Copy->Save Value to File.当然这个文件几百M(且只有一行),非常大,普通的文本编辑器根本看不出来(我在linux上使用了tail,然后不断的ctrl+c 最终看到了数据的开头),而这个数据也是当序列化到了config#cost字段时,只有一个正常的数据,其他后面全部为null
    • 所以数据问题确认完毕:cost字段里面除了一个正常的JSONObject外,剩余的全部是null

分析问题2--尝试重现

  • 最初的解决方法很简单 尝试通过代码方式能否复现
    • 即new一个HeroPersonality,其内部有一个getConfig,使用没有加IgnoreNonFieldGetter的方式序列化,看是否会造成大内存的占用
    • 很遗憾,未能复现
 HeroPersonality hp = new HeroPersonality();
 hp.setPersonalityLevel(1);
 String str = JSON.toJSONString(hp);
  • 然后尝试还原数值表最近的几个版本,看看是否有问题
    • 这个就是怀疑策划配置表有问题 导致这个cost字段在某些特殊情况下会如可能在加载的时候就变的很大
    • 很遗憾 未能复现
  • 分析源代码 确认是否可能启动加载配置表后这个cost字段就很大
    • debug DataConfigService
    • 发现的第一个问题是这个类混用了json-lib和fastjson(这个框架已更新,我们项目一直未更新),这里怀疑是否是json-lib有bug
    • 发现反序列化的过程是JSONLexer#扫描如大括号,逗号,方括号
    • 先找到了配置表的的第一个JSONObject,然后加到cost数组(注意此时JSONArray#list的底层数组长度已经被expand到了长度10) 然后遇到RBRACKET,就结束扫描了
    • 看到这里就有一个想法 是否是有可能遇到了特殊字符,如fastjson中的循环引用
    • 进而猜测到是否是策划配置的时候配置了公式?而且我也各种尝试在json的cost字段加各种特殊字符
    • 很遗憾,经过验证 未能复现
  • 尝试仔细看了一下堆快照,将PersonalityStrengthenConfig的10个对象内部数据都看了一下,和svn的策划表对比了一下,确认了是某个版本的数据。而这个版本的数据在本地测试是没有任何问题的
    • 排除策划配置数据问题

分析问题3--山重水复疑无路

  • 在我写本地测试代码重现的时候 我写了一个反序列化HeroPersonality的例子

  • 先用HeroPersonality序列化为一堆字符串,然后尝试在这堆字符串加入一些额外信息,然后再反序列化

  • 不经意的发现

    • 当进行一次HeroPersonality的反序列化后 再将原来的HeroPersonality再次序列化输出时惊奇的发现序列化后的cost字段多了一个null
    • 然后我就将反序列化代码放在循环里 然后再次输出 发现cost字段被加了很多null
  • 伪测试代码

PersonalityStrengthenConfig config = DataConfigService.
getSettingById(PersonalityStrengthenConfig.class, 1);

System.out.println("dcs.config1:" + config.cost);
System.out.println("dcs.config1:" + config.attr_num);

for (int i = 0; i < 10; i++) {
	String str1 = "{...}";
	JSON.parseObject(str1, HeroPersonality.class);
}

System.out.println("dcs.config2:" + config.cost);
System.out.println("dcs.config2:" + config.attr_num);
  • 结果输出

  • 这个结果让我惊喜,让我非常的肯定,cost中的大量null就是这样产生的,而且我最早就怀疑HeroPersonality中有一些非序列化的get方法有一些问题;而同样的attr_num也是JSONArray类型,就没有任何问题.问题初步锁定在HeroPersonality中的一个get方法.

分析问题4--源代码跟踪

  • 需要源代码debug,为什么在不断的调用反序列化的时候,cost被加入了大量的null
  • 下面这个是HeroPersonality的两个get方法,可以看到其中的getNextTrainCost调用了getConfig字段cost字段,下面从源代码debug的角度看一下为什么会每次反序列化都多了很多null
    • 首先getNextTrainCost这个getter中的nextTrainCost被当成了一个field,因为其返回值是一个JSONArray,其本身是可以作为setter用到的
    • 其反序列化,用json中"nextTrainCost"相关反序列化
    • 该字符串是[{"$ref":"$.config.cost[0]"} 即使用了fastjson的循环引用,这个反序列化出来为[null] (因为本身config压根就不属于field,只是一个get方法而已)
    • 然后调用setter(本身就是一个setter),得到cost,然后将这个[null] add到cost上
    • 然后每反序列化一次都向cost中加入一个[null],进而使cost越来越大(JSONArray#底层数组还会自动expand)
public JSONArray getNextTrainCost() {
	return ((PersonalityStrengthenConfig) getConfig()).cost;
}

@Override
public DataConfigItem getConfig() {
    return DataConfigService.getSettingById(PersonalityStrengthenConfig.class,
            personalityLevel);
}
  • 反序列化nextTrainCost
// FieldDeserializer#setValue 其中method就是getNextTrainCost() 即获取方法的返回值然后加了一个null
Collection collection = (Collection) method.invoke(object);
if (collection != null) {
      collection.addAll((Collection) value);
}

分析问题5--问题初步总结

  • 第一个问题出在了HeroPersonality中的getNextTrainCost方法引用了getConfig中的cost
    • 导致在反序列化的时候每次会将json#nextTrainCost中反序列化出来的JSONArray#add到cost上(相当于调用了setter方法)
    • 注意即使json#nextTrainCost不是循环引用(fastjson可关闭),即值就是引用的config#cost值,则每次反序列化一样也会将反序列化出来的JSONArray#add到cost,只不过这次不会是null而已
  • 第二个问题是最开始提到的我们正常序列化的时候就要带上IgnoreNonFieldGetter这个参数,不要将非field的get方法给序列化上去
    • 加上参数后,序列化后的json就没有nextTrainCost了,那么也就不会有反序列化的问题了,因为压根就扫描不到
    • 当然HeroPersonality这个getNextTrainCost也比较奇葩,用了引用的方式,其实完全没有必要,可以考虑干掉

解决问题1--为什么cost会那么大

  • 刚才我们已经基本肯定是因为错误模式下的反序列化会导致cost字段会越来越大,那么也不至于上亿次吧?
    • 这个我大概查了一下代码,很大几率是好友推荐模块和相关模块
    • 相关代码需要较频繁的对于离线镜像反序列化
    • 或者存在类似心跳业务处理
  • 解决办法
    • 很简单 就是一定要记住fastjson序列化的时候要加上IgnoreNonFieldGetter就可以了

扩展

  • mat还有很多强大的使用功能
    • Hisogram: list Number of instances per class
    • Dominator: TreeList the biggest objects and what they keep alive
    • Top Consumers: Print the most expensive objects grouped by class and by package
    • List Objects...
    • 此外还可以查看线程、Class Loader Explorer等

  • 其他有兴趣的可以了解
    • 什么是Shallow,什么是Retained
    • 如何计算一个Java对象的大小
Clone this wiki locally