问题描述

测试环境打开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&timestamp=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&timestamp=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);
    }
}

jackson序列化dubbo URL栈溢出问题

问题描述

原因分析

总结