因为一行Log日志导致的线上P1事故

前段时间，同事新增了一个特别简单的功能，晚上上线前review代码时想到公司拼搏进取的价值观临时他加一行 Log 日志，觉得就一行简单的日志基本上没啥问题，结果刚上完线后一堆报警，赶紧回滚了代码，找到问题然后删除添加日志的代码，重新上线完毕。之前网上看过这种消息，没想到自己却遇到了。

情景还原

定义一个 CountryDTO：

public class CountryDTO {
    private String country;

    public void setCountry(String country) {
        this.country = country;
    }

    public String getCountry() {
        return this.country;
    }

    public Boolean isChinaName() {
        return this.country.equals("中国");
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

定义测试类 FastJonTest：

public class FastJonTest {
    @Test
    public void testSerialize() {
        CountryDTO countryDTO = new CountryDTO();
        String str = JSON.toJSONString(countryDTO);
        System.out.println(str);
    }
}
1
2
3
4
5
6
7
8

运行时就报了一个空指针错误。

通过报错信息可以看出来是序列化的过程中执行了isChinaName()方法，这时候this.country变量为空，那么问题来了：

• 序列化为什么会执行isChinaName()呢？
• 引申一下，序列化过程中会执行那些方法呢?

源码分析

首先，我们通过Debug 来观察调用链路的堆栈信息。


调用链中的ASMSerializer_1_CountryDTO.write是FastJson使用asm技术动态生成了一个类ASMSerializer_1_CountryDTO。asm技术其中一项使用场景就是通过到动态生成类用来代替java反射，从而避免重复执行时的反射开销

JavaBeanSerizlier序列化原理

通过下图看出序列化的过程中，主要是调用JavaBeanSerializer类的write()方法。

而JavaBeanSerializer主要是通过getObjectWriter()方法获取，通过对getObjectWriter()执行过程的调试，找到比较关键的com.alibaba.fastjson.serializer.SerializeConfig#createJavaBeanSerializer方法，进而找到 com.alibaba.fastjson.util.TypeUtils#computeGetters。

public static List computeGetters(Class clazz, //
                                                 JSONType jsonType, //
                                                 Map aliasMap, //
                                                 Map fieldCacheMap, //
                                                 boolean sorted, //
                                                 PropertyNamingStrategy propertyNamingStrategy //
    ){
    //省略部分代码....
    Method[] methods = clazz.getMethods();
    for(Method method : methods){
        //省略部分代码...
        if(method.getReturnType().equals(Void.TYPE)){
            continue;
        }
        if(method.getParameterTypes().length != 0){
            continue;
        }
            //省略部分代码...
        JSONField annotation = TypeUtils.getAnnotation(method, JSONField.class);
        //省略部分代码...
        if(annotation != null){
            if(!annotation.serialize()){
                continue;
            }
            if(annotation.name().length() != 0){
                //省略部分代码...
            }
        }
        if(methodName.startsWith("get")){
         //省略部分代码...
        }
        if(methodName.startsWith("is")){
         //省略部分代码...
        }
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36

从代码中可以看出，大致分为三种情况：

• @JSONField(.serialize = false, name = “xxx”)注解
• getXxx() : get开头的方法
• isXxx()：is开头的方法

序列化流程图

下面是一段示例代码：

@JSONType(ignores = "otherName")
public class CountryDTO {
    private String country;

    public void setCountry(String country) {
        this.country = country;
    }

    public String getCountry() {
        return this.country;
    }

    public static void queryCountryList() {
        System.out.println("queryCountryList()执行!!");
    }

    public Boolean isChinaName() {
        System.out.println("isChinaName()执行!!");
        return true;
    }

    public String getEnglishName() {
        System.out.println("getEnglishName()执行!!");
        return "lucy";
    }

    public String getOtherName() {
        System.out.println("getOtherName()执行!!");
        return "lucy";
    }

    /**
     * case1: @JSONField(serialize = false)
     */
    @JSONField(serialize = false)
    public String getEnglishName2() {
        System.out.println("getEnglishName2()执行!!");
        return "lucy";
    }

    /**
     * case2: getXxx()返回值为void
     */
    public void getEnglishName3() {
        System.out.println("getEnglishName3()执行!!");
    }

    /**
     * case3: isXxx()返回值不等于布尔类型
     */
    public String isChinaName2() {
        System.out.println("isChinaName2()执行!!");
        return "isChinaName2";
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55

运行结果为：

isChinaName()执行!!
getEnglishName()执行!!
{"chinaName":true,"englishName":"lucy"}
1
2
3

代码规范

可以看出来序列化的规则还是很多的，比如有时需要关注返回值，有时需要关注参数个数，有时需要关注@JSONType注解，有时需要关注@JSONField注解；当一个事物的判别方式有多种的时候，由于团队人员掌握知识点的程度不一样，这个方差很容易导致代码问题，所以尽量有一种推荐方案。

这里推荐使用@JSONField(serialize = false)来显式的标注方法不参与序列化，下面是使用@JSONField注解后的代码，是不是一眼就能看出来哪些方法不需要参与序列化了。

public class CountryDTO {
    private String country;

    public void setCountry(String country) {
        this.country = country;
    }

    public String getCountry() {
        return this.country;
    }

    @JSONField(serialize = false)
    public static void queryCountryList() {
        System.out.println("queryCountryList()执行!!");
    }

    public Boolean isChinaName() {
        System.out.println("isChinaName()执行!!");
        return true;
    }

    public String getEnglishName() {
        System.out.println("getEnglishName()执行!!");
        return "lucy";
    }

    @JSONField(serialize = false)
    public String getOtherName() {
        System.out.println("getOtherName()执行!!");
        return "lucy";
    }

    @JSONField(serialize = false)
    public String getEnglishName2() {
        System.out.println("getEnglishName2()执行!!");
        return "lucy";
    }

    @JSONField(serialize = false)
    public void getEnglishName3() {
        System.out.println("getEnglishName3()执行!!");
    }

    @JSONField(serialize = false)
    public String isChinaName2() {
        System.out.println("isChinaName2()执行!!");
        return "isChinaName2";
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49

三个频率高的序列化场景

以上流程基本遵循，发现问题 --> 原理分析 --> 解决问题 --> 升华。但其实这段代码我并不满意，原因是和 FastJson 依赖太高了。我想要的效果是，不依赖任何特定的 JSON 序列化框架。当我需要替换掉它的时候，随时可以替换掉。

并且在写代码时，不要过于依赖日志。打日志只需要打紧要且关键的信息即可，不要什么日志都打，我曾见过一个系统，一个小时，把 128G 磁盘跑满的管理系统。几乎没啥并发，但几乎每个请求都输出几 M 的日志，这件事我后面会单独拿出来讲讲。

关于@JSONField和@JSONType等特性注解，后面我会在团队内规范并给出新的解耦方案，把它们移除掉。