jackson版本:2.8.1
问题描述
测试环境打开dubbo的result log日志出现如下异常
2019-12-24 11:16:03,753 ERROR [DubboMonitorSendTimer-thread-2] com.....dubbo.utils.ResultLogger:log:34 记录日志异常
com.fasterxml.jackson.databind.JsonMappingException: Infinite recursion (StackOverflowError) (through reference chain: com.alibaba.dubbo.common.URL["backupUrls"]->java.util.ArrayList[0]->com.alibaba.dubbo.common.URL["backupUrls"]->java.util.ArrayList[0]->com.alibaba.dubbo.common.URL["backupUrls"]->java.util.ArrayList[0]->com.alibaba.dubbo.common.URL["backupUrls"]->java.util.ArrayList[0]->com.alibaba.dubbo.common.URL["backupUrls"]->java.util.ArrayList[0]->com.alibaba.dubbo.common.URL["backupUrls"]->java.util.ArrayList[0]->com.alibaba.dubbo.common.URL["backupUrls"]->省略N多相同日志->com.alibaba.dubbo.common.URL["backupUrls"])
at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:706) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:155) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serializeContentsUsing(IndexedListSerializer.java:142) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serializeContents(IndexedListSerializer.java:88) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serialize(IndexedListSerializer.java:79) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serialize(IndexedListSerializer.java:18) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:693) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at 省略N多相同日志com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:690) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:155) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serializeContentsUsing(IndexedListSerializer.java:142) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serializeContents(IndexedListSerializer.java:88) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serialize(IndexedListSerializer.java:79) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serialize(IndexedListSerializer.java:18) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:693) ~[jackson-databind-2.8.1.jar!/:2.8.1]
at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:690) ~[jackson-databind-2.8.1.jar!/:2.8.1]
原因分析
堆栈中可以看到是我们内部写Result log日志时出现了该异常,源码如下
import com.fasterxml.jackson.databind.ObjectMapper;
...
private static ObjectMapper objectMapper = new ObjectMapper();
...
public static void log(Invoker<?> invoker, Invocation invocation, Object result, Long consume) {
try {
LOGGER.info("调用方法|提供者:{}, 方法:{}, 参数:{}, 响应:{}, 耗时:{}", new Object[]{invoker.getInterface().getName(), invocation.getMethodName(), objectMapper.writeValueAsString(invocation.getArguments()), objectMapper.writeValueAsString(result), consume});
} catch (JsonProcessingException var5) {
LOGGER.error("记录日志异常", var5);
}
}
由于问题是必现问题,本地断点查看发现是使用jackson对dubbo URL对象序列化时出现的问题。具体什么为什么会出现?查看jackson源码实现
首先写一份复现代码跟着断点一步步分析,复现代码如下:
import com.alibaba.dubbo.common.URL;
import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.ObjectMapper;
/**
* @author 会灰翔的灰机
* @date 2019/12/24
*/
public class ReplayBug {
public static void main(String[] args) throws JsonProcessingException {
URL url = URL.valueOf("count://192.168.96.162:14300/com.gallant.dispatch.provider.DispatchModeShopProvider/queryCache?application=dispatch-config-dispatch-mode&concurrent=1&consumer=192.168.96.162&elapsed=363&failure=0&input=14982&interface=com.dianwoba.dispatch.provider.DispatchModeShopProvider&max.concurrent=2&max.elapsed=86&max.input=454&max.output=18&method=queryCache&output=594&success=66×tamp=1577174591802");
System.out.println(url);
ObjectMapper objectMapper = new ObjectMapper();
String result = objectMapper.writeValueAsString(url);
System.out.println(result);
}
}
DefaultSerializerProvider.serializeValue序列化对象,获取对象class并根据class查找Json序列化实现
Class<?> cls = value.getClass();
// true, since we do want to cache root-level typed serializers (ditto for null property)
final JsonSerializer<Object> ser = findTypedValueSerializer(cls, true, null);
返回序列化对象:BeanSerializer for com.alibaba.dubbo.common.URL,调用父类方法SerializerBase.serializeFields遍历fields属性执行序列化
异常中可以看到是backupUrls属性序列化时出现了循环导致栈溢出,断点也发现每次走完backupAddress属性都会重新回归到protocol属性,也就是出现了死循环
for (final int len = props.length; i < len; ++i) {
BeanPropertyWriter prop = props[i];
if (prop != null) { // can have nulls in filtered list
prop.serializeAsField(bean, gen, provider);
}
}
序列化属性BeanPropertyWriter.serializeAsField
public void serializeAsField(Object bean, JsonGenerator gen,
SerializerProvider prov) throws Exception {
// 如果访问属性方法不为空则调用获取,否则读取field,
// 此时访问方法不为空:public java.util.List com.alibaba.dubbo.common.URL.getBackupUrls()
final Object value = (_accessorMethod == null) ? _field.get(bean)
: _accessorMethod.invoke(bean);
// Null handling is bit different, check that first
if (value == null) {
if (_nullSerializer != null) {
gen.writeFieldName(_name);
_nullSerializer.serialize(null, gen, prov);
}
return;
}
// then find serializer to use,当前序列化对象为空,value类型为ArrayList<URL>
JsonSerializer<Object> ser = _serializer;
if (ser == null) {
Class<?> cls = value.getClass();
// 动态序列化对象为PropertySerializerMap$Single
PropertySerializerMap m = _dynamicSerializers;
ser = m.serializerFor(cls);
// 返回为空继续查找序列化实现
if (ser == null) {
// 返回IndexedListSerializer
ser = _findAndAddDynamic(m, cls, prov);
}
}
// and then see if we must suppress certain values (default, empty)
...
// For non-nulls: simple check for direct cycles
// 判断是否循环引用
if (value == bean) {
// three choices: exception; handled by call; or pass-through
if (_handleSelfReference(bean, gen, prov, ser)) {
return;
}
}
gen.writeFieldName(_name);
// 序列化value
if (_typeSerializer == null) {
ser.serialize(value, gen, prov);
} else {
ser.serializeWithType(value, gen, prov, _typeSerializer);
}
}
序列化列表对象,流程类似上面描述的默认序列化流程,区别是当前value是列表,需要遍历列表,对列表元素逐个进行序列化。没错问题就在这里,我们查看URL返回的backupUrls中确实包含自己本身如下图
URL url = URL.valueOf("count://192.168.96.162:14300/com.gallant.dispatch.provider.DispatchModeShopProvider/queryCache?application=dispatch-config-dispatch-mode&concurrent=1&consumer=192.168.96.162&elapsed=363&failure=0&input=14982&interface=com.dianwoba.dispatch.provider.DispatchModeShopProvider&max.concurrent=2&max.elapsed=86&max.input=454&max.output=18&method=queryCache&output=594&success=66×tamp=1577174591802");
List<URL> backupUrls = url.getBackupUrls();
System.out.println(url+"\n"+backupUrls);
总结
jackson校验了自身属性引用自身的场景,但是没有校验自身链表属性中的元素是否有对自身的引用,所以出现了死循环问题。于是我们编写一个案例验证确实如此,代码如下,测试当前最新的jackson-2.10.1版本中依然存在该问题
import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.ObjectMapper;
import java.io.Serializable;
import java.util.ArrayList;
import java.util.List;
import lombok.Data;
/**
* @author 会灰翔的灰机
* @date 2019/12/24
*/
@Data
public class Car implements Serializable {
private static final long serialVersionUID = 6693253762391586491L;
private Car car;
private List<Car> cars;
public static void main(String[] args) throws JsonProcessingException {
// selfRef();
selfListRef();
}
// 会抛出自引用异常:Exception in thread "main" com.fasterxml.jackson.databind.JsonMappingException: Direct self-reference leading to cycle (through reference chain: com.dianwoba.dispatch.Car["car"])
private static void selfRef() throws JsonProcessingException {
Car car = new Car();
car.setCar(car);
ObjectMapper objectMapper = new ObjectMapper();
String result = objectMapper.writeValueAsString(car);
}
// 会抛出栈溢出异常
private static void selfListRef() throws JsonProcessingException {
Car car = new Car();
List<Car> cars = new ArrayList<>();
cars.add(car);
car.setCars(cars);
ObjectMapper objectMapper = new ObjectMapper();
String result = objectMapper.writeValueAsString(car);
}
}