关于我加了一行日志搞崩了服务这件小事

站长

2023年06月12日 19:51 · 阅读数 18

前言

周三的时候，组内出现了一个线上问题，影响到了若干个用户的下单、支付等操作。然而实际查询到问题的原因时，发现只是由于一行小小的日志打印导致的错误。

以下的文章内容分为主要分为三部分：

1、对案件的发生进行回顾；

2、分析案件发生的原因；

3、对案件总结与反思

以三章内容来回顾出现的问题，以及提供未来的预防策略。

案件回顾

周三的时候，服务频繁收到报警，系统频繁爆出空指针异常。值班同学根据报错的错误栈，快速定位到了错误的代码行。

at com.alibaba.fastjson.serializer.JSONSerializer.write(JSONSerializer.java:285)
at com.alibaba.fastjson.JSON.toJSONString(JSON.java:696)

找到代码行后却让值班同学感到疑惑：“这个明显是fastjson的日志打印呀，这也会有什么错误么？”。旁边的同事看完却惊呼一声：“fastJson打印日志会调用对象内的其余的get方法的呀！”。

（PS：该对象是一个DDD的核心域对象，其中包含一些业务场景方法被命名为getXXX方法的，因此执行Json序列化打印也就可能因为部分数据为空而出现空指针。）

定位到了问题原因，本着优先止损的原则，值班同事快速上线代码删除了这行日志打印。系统暂时的恢复了正常，没有再出现新增的报错信息了。然而后续还有漫长的数据修复、更正的过程。

案件分析：

案件复原：

本质上来说，这起线上事故出现的原因主要是因为fastJson序列化时，会将手工编写的一些方法认为是待输出属性对象，那么如果这些方法包含一些业务逻辑代码的时候，就会存在出现异常的风险。这里我们简单复现一下场景：

@Data
public class CoreData {
    //正常的属性
    public String normalProperties = "normalProperties";

    /**
     * 以get开头的方法 不是期望输出的属性
     * @return
     */
    public String getFuncProperties(){
        return "getFuncProperties";
    }

    /**
     * 以is开头的方法 不是期望输出的属性
     * @return
     */
    public Boolean isType(){
        return true;
    }
}

如上代码是我们编写的一个纯代码类，可以看到，我们实际期望设置的属性应该只有一个normalPropertites。

public static void main(String[] args) {
    CoreData data = new CoreData();
    String dataString = JSONObject.toJSONString(data);
    System.out.println(dataString); // 对应正常的业务逻辑
}

进而我还写了一段针对当前对象进行打印的代码，从上可以看到，就是简单的对对象进行JSON序列化后打印输出。按照我们的期望来说，只是期望输出normalProperties这一个固有的字符串属性。随后我运行了代码，得到了如下的结果：

关于我加了一行日志搞崩了服务这件小事

可以看到，一个类型+两个方法，都被JSON序列化后输出了。那么如果此时我们在getFuncProperties()这样的方法中如果出现了异常，就会影响整个业务的运行。例如我们把方法改成如下的例子：

public String getFuncProperties(){
    double a = 2/0;
    return "getFuncProperties";
}

关于我加了一行日志搞崩了服务这件小事

可以看到，我们原本的逻辑可能只是想输出normalProperties属性，但是因为getFuncProperties2/0是无法进行运算的，导致了系统直接报错了。那么此时，main函数中的输出方法（对应于我们正常业务逻辑），也就无法再继续执行了，而这在生产环境上无疑是致命的。

背后原理：

(PS: 以下讨论内容均基于1.2.9版本的fastJson。)

根据报错的问题点，结合debug，很快找到了问题所在：

关于我加了一行日志搞崩了服务这件小事

在**com.alibaba.fastjson.serializer.JSONSerializer#write(java.lang.Object)**这个方法中，Fastjson所创建的ObjectSerializer对象中，nature下所包含的getters对象有三个。这明显不符合我们的预期。那么我们就需要找到他是如何获取到这三个方法的。紧跟着我们进行追入，在com.alibaba.fastjson.serializer.SerializeConfig#getObjectWriter方法下找到了这行代码：

put(clazz, createJavaBeanSerializer(clazz));

很明显，这里的createJavaBeanSerializer(clazz)创建了javaBean的序列化器。对于该方法，其主要的逻辑流程就是判断当前的对象类型是否符合使用ASM的序列化器。这里一通判断下来，是符合采用ASM序列化的要求的，因此，我们又进一步定位到了如下代码：

ObjectSerializer asmSerializer = createASMSerializer(clazz);

在createASMSerializer对应的方法中，最关键的代码莫过于下面这行了：

List<FieldInfo> unsortedGetters = TypeUtils.computeGetters(clazz, jsonType, aliasMap, false);

这力的代码会生成对应的fieldInfo对象，也正好对应了前面我们涉及到的那三个方法，这里让我们仔细看一下com.alibaba.fastjson.util.TypeUtils#computeGetters所对应的代码：

public static List<FieldInfo> computeGetters(Class<?> clazz, JSONType jsonType, Map<String, String> aliasMap, boolean sorted) {
    Map<String, FieldInfo> fieldInfoMap = new LinkedHashMap<String, FieldInfo>();
    for (Method method : clazz.getMethods()) {
        String methodName = method.getName();
        int ordinal = 0, serialzeFeatures = 0;
        String label = null;
		//判读当前方法是否为静态的
        if (Modifier.isStatic(method.getModifiers())) {
            continue;
        }
		//若返回值为void则此时不需要处理
        if (method.getReturnType().equals(Void.TYPE)) {
            continue;
        }
		//若此时入参不为空则跳过
        if (method.getParameterTypes().length != 0) {
            continue;
        }
		//若返回类型是类加载器也进行跳过。
        if (method.getReturnType() == ClassLoader.class) {
            continue;
        }
		//若方法名是getMetaClass也跳过
        if (method.getName().equals("getMetaClass")
            && method.getReturnType().getName().equals("groovy.lang.MetaClass")) {
            continue;
        }
		//获取方法的有关JSONField的注释
        JSONField annotation = method.getAnnotation(JSONField.class);
        if (annotation == null) {
            //若当前类为空，则再获取父类的。
            annotation = getSupperMethodAnnotation(clazz, method);
        }
        if (annotation != null) {
            //若父类不为空则进行序列化的判断，我们使用的例子无继承，这部分先忽略不看。
            ......
        }
        //重点来了，判断当前是否以get开头
        if (methodName.startsWith("get")) {
            //长度小于4，即不满足getXX的格式的，直接跳过。
            if (methodName.length() < 4) {
                continue;
            }
            //getClass的进行跳过
            if (methodName.equals("getClass")) {
                continue;
            }
			//获取第四个位置的字符
            char c3 = methodName.charAt(3);
            String propertyName;
            if (Character.isUpperCase(c3) || c3 > 512 ) {
                //若方法遵循驼峰的写法：则依次取出对应的名称信息
                if (compatibleWithJavaBean) {
                    propertyName = decapitalize(methodName.substring(3));
                } else {
                    propertyName = Character.toLowerCase(methodName.charAt(3)) + methodName.substring(4);
                }
            } else if (...) {
                //这里针对部分特殊的写法：如get_X、getfX做了特殊的判断处理。
            } else {
                continue;
            }
			// 方案一 - 这里会根据当前属性名和clazz来判断是否被忽略了，详见@JsonType注解
            boolean ignore = isJSONTypeIgnore(clazz, propertyName);
			// 如果忽略了，就不再往下走了
            if (ignore) {
                continue;
            }
			//此时根据属性和类获取对应的值对象。
            Field field = ParserConfig.getField(clazz, propertyName);
            JSONField fieldAnnotation = null;
            if (field != null) {
                //方案二 - 会获取属性对应的JSONField注解
                // 如果该注解的serialize属性是false，那么也不会继续往下去加载逻辑
                fieldAnnotation = field.getAnnotation(JSONField.class);
                if (fieldAnnotation != null) {
                    if (!fieldAnnotation.serialize()) {
                        continue;
                    }
					//获取顺序
                    ordinal = fieldAnnotation.ordinal();
                    serialzeFeatures = SerializerFeature.of(fieldAnnotation.serialzeFeatures());
                    if (fieldAnnotation.name().length() != 0) {
                        //获取名字
                        propertyName = fieldAnnotation.name();
                        if (aliasMap != null) {
                            propertyName = aliasMap.get(propertyName);
                            if (propertyName == null) {
                                continue;
                            }
                        }
                    }
                    if (fieldAnnotation.label().length() != 0) {
                        label = fieldAnnotation.label();
                    }
                }
            }
            if (aliasMap != null) {
                propertyName = aliasMap.get(propertyName);
                if (propertyName == null) {
                    continue;
                }
            }
            //这里会新构建一个fieldInfo对象，并存放到fieldInfoMap中进行保存
            FieldInfo fieldInfo = new FieldInfo(propertyName, method, field, clazz, null, ordinal, serialzeFeatures,
                                                annotation, fieldAnnotation, label);
            fieldInfoMap.put(propertyName, fieldInfo);
        }
        //紧接着第二部分是关于isXXX的方法
        if (methodName.startsWith("is")) {
            if (methodName.length() < 3) {
                continue;
            }
            char c2 = methodName.charAt(2);
            String propertyName;
            if (Character.isUpperCase(c2)) {
                if (compatibleWithJavaBean) {
                    propertyName = decapitalize(methodName.substring(2));
                } else {
                    propertyName = Character.toLowerCase(methodName.charAt(2)) + methodName.substring(3);
                }
            } else if (...) {
            	//同上面几乎一样，也是针对is_x这类特殊写法做了处理。
            }else {
                continue;
            }
            Field field = ParserConfig.getField(clazz, propertyName);
            if (field == null) {
                field = ParserConfig.getField(clazz, methodName);
            }
            JSONField fieldAnnotation = null;
            if (field != null) {
                //同样是对JSONField注解做处理。
                fieldAnnotation = field.getAnnotation(JSONField.class);
                if (fieldAnnotation != null) {
                    if (!fieldAnnotation.serialize()) {
                        continue;
                    }
                    ordinal = fieldAnnotation.ordinal();
                    serialzeFeatures = SerializerFeature.of(fieldAnnotation.serialzeFeatures());
                    if (fieldAnnotation.name().length() != 0) {
                        propertyName = fieldAnnotation.name();
                        if (aliasMap != null) {
                            propertyName = aliasMap.get(propertyName);
                            if (propertyName == null) {
                                continue;
                            }
                        }
                    }
                    if (fieldAnnotation.label().length() != 0) {
                        label = fieldAnnotation.label();
                    }
                }
            }
            if (aliasMap != null) {
                propertyName = aliasMap.get(propertyName);
                if (propertyName == null) {
                    continue;
                }
            }
            FieldInfo fieldInfo = new FieldInfo(propertyName, method, field, clazz, null, ordinal, serialzeFeatures,
                                                annotation, fieldAnnotation, label);
            fieldInfoMap.put(propertyName, fieldInfo);
        }
    }
	//最后，又是对所有的常规属性做相应的处理，避免因为某个属性没写getX()方法而得不到序列化。整体的加载逻辑同上。
    for (Field field : clazz.getFields()) {
        if (Modifier.isStatic(field.getModifiers())) {
            continue;
        }
        JSONField fieldAnnotation = field.getAnnotation(JSONField.class);
        int ordinal = 0, serialzeFeatures = 0;
        String propertyName = field.getName();
        String label = null;
        if (fieldAnnotation != null) {
            if (!fieldAnnotation.serialize()) {
                continue;
            }
            ordinal = fieldAnnotation.ordinal();
            serialzeFeatures = SerializerFeature.of(fieldAnnotation.serialzeFeatures());
            if (fieldAnnotation.name().length() != 0) {
                propertyName = fieldAnnotation.name();
            }
            if (fieldAnnotation.label().length() != 0) {
                label = fieldAnnotation.label();
            }
        }
        if (aliasMap != null) {
            propertyName = aliasMap.get(propertyName);
            if (propertyName == null) {
                continue;
            }
        }

        if (!fieldInfoMap.containsKey(propertyName)) {
            FieldInfo fieldInfo = new FieldInfo(propertyName, null, field, clazz, null, ordinal, serialzeFeatures,
                                                null, fieldAnnotation, label);
            fieldInfoMap.put(propertyName, fieldInfo);
        }
    }

    List<FieldInfo> fieldInfoList = new ArrayList<FieldInfo>();

    boolean containsAll = false;
    String[] orders = null;

    JSONType annotation = clazz.getAnnotation(JSONType.class);
    if (annotation != null) {
        orders = annotation.orders();

        if (orders != null && orders.length == fieldInfoMap.size()) {
            containsAll = true;
            for (String item : orders) {
                if (!fieldInfoMap.containsKey(item)) {
                    containsAll = false;
                    break;
                }
            }
        } else {
            containsAll = false;
        }
    }

    if (containsAll) {
        for (String item : orders) {
            FieldInfo fieldInfo = fieldInfoMap.get(item);
            fieldInfoList.add(fieldInfo);
        }
    } else {
        for (FieldInfo fieldInfo : fieldInfoMap.values()) {
            fieldInfoList.add(fieldInfo);
        }
        if (sorted) {
            Collections.sort(fieldInfoList);
        }
    }
    return fieldInfoList;
}

代码有点长，听我一点点地慢慢解释。整个代码其实比较容易理解，我尝试从我们常规角度来理解下。fastJson组件的发明者认为，类中常见需要序列化的类型有三种：

1、getX()方法；

2、isX()方法;

3、没有写getX()方法的固有变量。

围绕这三种类型他做的事都是类似的。这里我们先以getX()方法为例子展开说明，要获取到所有的getX()方法，并对他们解析，主要分为以下四个步骤：

1、获取到所有的类下的方法信息

这个可以通过class<?>.getMethods()方法获得，如下是我coreData类的所有方法。

关于我加了一行日志搞崩了服务这件小事

2、判断符合规范的getXXX方法

在获取到了所有的method以后，我们自然需要判断哪些是符合规范的getXX方法。在组件中是这么判断的：

if (methodName.startsWith("get")) {
    //此时做相应的处理逻辑  
}

没错，就是这么粗暴简单。

3、根据JSONType判断是否需要加载

那么获取到这些方法就一定要加载了吗？当然不是！对于getter方法，fastJson会首先判断当前的属性，是否已被包含在了类的@JSONType(ignores = "xxx")下，如果包含在了其中，那么此时就不会去将该方法保存到待序列化的列表中。局限点在于该种写法只会对get方法生效，对于isXXX和普通属性是不会生效的。

// 方案一 - 这里会根据当前属性名和clazz来判断是否被忽略了，详见@JsonType注解
boolean ignore = isJSONTypeIgnore(clazz, propertyName);
// 如果忽略了，就不再往下走了
if (ignore) {
    continue;
}

关于我加了一行日志搞崩了服务这件小事

4、根据JSONField判断是否需要加载

什么？你说采用JSONType写一大堆不方便？fastJson自然也是想到了，那么此时就可以采用@JSONField(serialize = false)的方式在对单独的属性或方法进行标注。也能起到忽略的作用。

关于我加了一行日志搞崩了服务这件小事

到此，以getXX()方法的解析判断就完成了，当然其中还有一些更为细致的判断逻辑，如跳过getMetaClass、返回值为空的跳过等等逻辑。但大体上已经不影响我们的分析了。isXXX和固有变亮的解析几乎相似。至此，我们已经大致了解了整个解析的原理。当然为了验证我们的逻辑的正确性，我对原本coreData的代码做了一下改造并进行了试验，具体内容如下所示：

@Data
@JSONType(ignores = "funcProperties")
public class CoreData {

    //正常的属性
    public String normalProperties = "normalProperties";

    /**
     * 以get开头的方法
     * @return
     */
    public String getFuncProperties(){
        double a = 2/0;
        return "getFuncProperties";
    }

    /**
     * 以is开头的方法
     * @return
     */
    @JSONField(serialize = false)
    public Boolean isType(){
        return true;
    }

    /**
     * 用于跳过，检查方法是否判断
     * @return
     */
    public String skipFuncProperties(){
        double a = 2/0;
        return "getFuncProperties";
    }
}

简要来说，这里对getFuncProperties方法，我才用了@JSONType(ignores = "funcProperties")将其进行忽略，而对于isType方法，我则用单个的@JSONField(serialize = false)对其进行忽略，如果我们的结论成立，那么此时应该只会保存一个normalProperties属性的输出，且不存在出现报错的情况。

关于我加了一行日志搞崩了服务这件小事

事实证明，我们是对的。

案件总结与反思：

在经历了这次惨痛的教训之后，有哪些是值得我们深入关注去思考和反思的呢？

1、在编写方法的时候尽量避免才用getXXX、isXXX的方法进行书写，这会导致部分框架的解析出现问题。（这个点也是我曾经在JAVA开发手册中看到的，想必也是前人被坑过了。）

2、如果非要这样写，那么此时需要评估好当前这个方法是否需要被一些框架进行解析，如果不需要，尝试对这些类型属性添加基本的忽略操作。类似@JSONField(seralize = false)、@Trasient等注解。

3、避免在对象中参杂进复杂的业务逻辑。（当然这条并不一定正常，对于DDD的充血模型，有时候是需要一定的业务逻辑的混合的。）

吃一堑长一智，如此一来才能避免在未来犯下相同的错误呀～