Spring + Jackson有可能导致类数量爆炸

上周四线上的一个应用突然假死状态,通过gc log发现正在频繁的full gc,从gc log上可以看出是Metaspace导致频繁full gc(实际上这个时候Metaspace还没满,还有几十M的剩余),然后用jmap -histo <pid>发现有大量的GeneratedConstructorAccessorXXX和GeneratedMethodAccessorXXX类型的对象(总共有两万多个)。

熟悉java反射的同学应该知道,这两个类都是在反射过程中调用Method.invoke产生的,前者顾名思义就是调用构造函数产生的,后者就是调用普通的方法产生的,生成这个类的代码在:MethodAccessorGenerator

private static synchronized String generateName(boolean isConstructor,boolean forSerialization){if (isConstructor) {if (forSerialization) {int num = ++serializationConstructorSymnum;return "jdk/internal/reflect/GeneratedSerializationConstructorAccessor" + num;else {int num = ++constructorSymnum;return "jdk/internal/reflect/GeneratedConstructorAccessor" + num;}else {int num = ++methodSymnum;return "jdk/internal/reflect/GeneratedMethodAccessor" + num;}}

看到大量的这两个类,第一个念头是谁使用反射没有复用Method对象吧(意思是,我们如果使用反射的时候,如果这个反射会频繁的调用,那么不要每次都去拿Method,最好将method缓存着,不然成本会很高的)。有了这个念头后,我就想如果能把这个类代码dump下来,然后统计一下看看,是不是有些方法对应有很多的GeneratedMethodAccessor,那就基本上知道是什么方法的反射导致的了,然后翻翻代码基本上能确定原因。

正好github上有人写了个工具,可以将class的字节码dump出来:dumpclass

java -jar dumpclass.jar -p <pid> sun.reflect.GeneratedMethodAccessor*

这样就可以将所有的这样的类的字节码全部dump出来了,有类字节码然后我们使用javap对字节码进行反编译,然后就可以进行统计了。遗憾的是,最后发现几乎没有两个不同的GeneratedMethodAccessor类属于同一个方法反射生成的。线索到这里就断了,那说明不是因为没有缓存Method导致的,而是正常的反射使用。然后我随机的看了几个GeneratedMethodAccessor类的字节码,所有的方法基本上都是getter,那这说明什么呢?一般如果是业务代码里使用反射,大部分是调用一个业务方法,而什么会去调用getter呢?比如序列化,比如json。这个时候我正好看到这个应用里有很多地方打印日志,而打印日志的时候是直接使用Jackson将对象序列化之后打印,这里使用的Jackson序列化工具是公共包(common-api)里用Jackson封装的一个工具类。

然后我就怀疑是不是这个应用记录日志太多了,然后Jackson序列化的时候会反射调用对象的getter,然后产生大量的这个GeneratedMethodAccessor类呢?于是我就自己写了个简单的测试,我发现公共包的这个工具类并不会去调用Method.invoke,这就奇怪了,不是Jackson导致的?

不过正好这个时候,我在GeneratedMethodAccessor字节码里除了看到了getter,也看到了setter方法。有了setter方法,那说明应该不是打印日志导致的,打印日志只会序列化不会反序列化,线索再次中断。

然后我就从GeneratedMethodAccessor的字节码里找到一个类,然后查找引用,最后找到了Spring的Controller这一层。这个应用提供了非常非常多的HTTP API,然后这些Controller基本上都是返回对象的方式返回响应,并且Controller的参数接受的也是对象,类似下面这样的:

@RequestMapping(value = "/api/web/businessInfo/list/v2", method = RequestMethod.POST)@JsonResponseBody//返回BusinessInfoGridVO对象,接受BusinessInfoListVO对象public Pager<BusinessInfoGridVO> BusinessInfoListV2(@RequestBody BusinessInfoListVO infoListVO) {

我们都知道,返回对象的方式返回响应,在Spring框架里,会使用HttpMessageConverter进行序列化,然后将序列化结果吐给客户端,而接受对象也是在Spring框架里反序列化成对象。然后我找到了这个这个应用的HttpMessageConverter配置(实际上公司的web应用,如果引入了common-web, common-web-support,是不需要配置HttpMessageConverter的):

@Overridepublic void configureMessageConverters(List<HttpMessageConverter<?>> converters) {super.configureMessageConverters(converters);converters.add(new MappingJackson2HttpMessageConverter(JsonUtil.getObjectMapperInstance()));}

通过这里我们可以看到使用的是MappingJackson2HttpMessageConverter,而传入MappingJackson2HttpMessageConverter构造函数的是一个ObjectMapper:JsonUtil.getObjectMapperInstance()。这个JsonUtil是这个应用自己封装的一个json工具类(非来自common包),然后我就用这个工具类写个序列化测试,惊奇的发现产生了GeneratedMethodAccessor。看来是有什么配置导致公共包里的和这里的两个json工具类的差异。但是这个ObjectMapper的配置太多了,很难看出来是什么差异,而且我也对Jackson本身的机制不太熟悉,只好祭起了debug大法。

我先debug了一下公共包里的json工具类,发现这个类虽然不产生GeneratedMethodAccessor,但是会产生另外一个类:Xxx$Access4JacksonSerializer00000000,最前面的Xxx是你原来的类名。但是Jackson生成的机制和反射生成机制不同的是一个类只会产生一个这个类,而使用Java原生的反射是每个方法产生一个类。更恐怖的是,Java的反射给每个类都实例化一个单独Classloader(DelegatingClassLoader,而这也是导致Metaspace频繁full gc的其中一个原因,后文再说):

static Class<?> defineClass(String name, byte[] bytes, int off, int len,final ClassLoader parentClassLoader){ClassLoader newLoader = AccessController.doPrivileged(new PrivilegedAction<ClassLoader>() {public ClassLoader run() {return new DelegatingClassLoader(parentClassLoader);}});return unsafe.defineClass(name, bytes, off, len, newLoader, null);}

那么我们可以想象:假设我们有一万个getter+setter(对于大量的POJO来讲也不算多,也就总共5000个field)。

那为什么公共包里的JsonUtil不调用Method.invoke呢,经过debug找到了生成Xxx$Access4JacksonSerializer00000000的代码位置:PropertyAccessorCollector。然后设置断点,记录stacktrace,在每个stacktrack包含的方法都设置断点,然后再debug这个应用自己封装的JsonUtil类,发现这个JsonUtil没进入到这个路径,然后就打开两台电脑同时debug,看看是在哪里开始走不同的路径了,最终发现在这里com.fasterxml.jackson.databind.ser.BeanSerializerFactory:

// Need to allow reordering of properties to serializeif (_factoryConfig.hasSerializerModifiers()) {for (BeanSerializerModifier mod : _factoryConfig.serializerModifiers()) {props = mod.orderProperties(config, beanDesc, props);}}

这就很明显了,_factoryConfig.hasSerializerModifiers()看起来是配置的东西导致的。曙光来了,后来发现是这个是下面这个配置导致hasSerializerModifiers为true,在公共包的json工具类里是有这个配置的,而这个JsonUtil是没有配置的。

objectMapper.registerModules(new AfterburnerModule())

现在问题基本上确定了,也就是Spring使用的Jackson序列化导致的,只需要改一下配置基本上就没有问题了(AfterburnerModule github)。

但是在查这个问题的时候,还有另外一个问题:其实频繁发生full gc的时候,Metaspace并没有满。那么没有满为啥就频繁full gc呢,其实Metaspace的内存分配是按照classloader分配的,也就是会给每个classloader分配一块内存,所以如果存在大量的classloader的话,会有很严重的碎片问题,碎片多了自然没有满就会full gc了。

后记

1. 经常看到各种项目里有JsonUtil, HttpUtil,DateUtil, StringUtil等等各种Util,强烈不建议这样做,一来是没有什么必要,二来也让后来的人产生困惑,三来如果有bug什么的公共包里可以集中修复,另外公共包里的类也经过了更充分的测试。

2. 很多应用里打印了大量的日志,主要是担心查问题的时候没有线索,但是直接将对象序列化的方式打印日志并不可取,首先是这样打印的日志太多太多了,完全没有必要,消耗资源不说,还有可能泄露一些敏感信息。那么即使要将对象完全打印出来,最好也是通过覆盖toString的方法来输出日志,使用lombok等工具覆盖toString方法也几乎没有什么成本。

3. HttpMessageConverter这个配置公共包里已经配置好了,不需要自己再定义

注:转载自公司内wiki