测试环境打开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
返回序列化对象: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 JsonSerializer
序列化列表对象,流程类似上面描述的默认序列化流程,区别是当前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 backupUrls = url.getBackupUrls();System.out.println(url+"
"+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 */@Datapublic class Car implements Serializable { private static final long serialVersionUID = 6693253762391586491L; private Car car; private List 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 cars = new ArrayList<>(); cars.add(car); car.setCars(cars); ObjectMapper objectMapper = new ObjectMapper(); String result = objectMapper.writeValueAsString(car); }}
留言与评论(共有 0 条评论) “” |