×
Community Blog System Errors Caused by a Line of Log

System Errors Caused by a Line of Log

This article records the system errors caused by a line of log and the author's approach to solving the problem.

1

By Bafan

1. Problem Discovery

During an iteration development process, a new line of code was added for printing logs, resulting in an error in the main process of the system. At that time, it was puzzling for me how a single line of log could trigger a bug.

The newly added code for printing logs:

log.info("batch save receipt context:{}", JSON.toJSONString(context));

Here is a screenshot of the error log at that time:

2

2024-05-15 17:43:19.287|2132b44116764541988934881eca7a|[oms-thread-726]|ERROR|com.xxx.config.GlobalExceptionHandler|user_trace^xxxxx|1625792701351985152|## GlobalExceptionHandler,Host:33.xx.xx.xx invokes url:http://33.xx.xx.xx:7001/api/v1/emp/trans/receipt/submit errorMsg:com.alibaba.fastjson.JSONException: write javaBean error, fastjson version 1.2.76, class com.xxx.bo.emp.BatchSaveReceiptContext, write javaBean error, fastjson version 1.2.76, class com.xxx.po.EmpTransReceipt, fieldName : 0
at com.alibaba.fastjson.serializer.JavaBeanSerializer.write(JavaBeanSerializer.java:544)
at com.alibaba.fastjson.serializer.JavaBeanSerializer.write(JavaBeanSerializer.java:154)
at com.alibaba.fastjson.serializer.JSONSerializer.write(JSONSerializer.java:312)
at com.alibaba.fastjson.JSON.toJSONString(JSON.java:793)
at com.alibaba.fastjson.JSON.toJSONString(JSON.java:731)
at com.alibaba.fastjson.JSON.toJSONString(JSON.java:688)
at com.xxx.impl.EmpTransHandleServiceImpl.doSaveTransReceipts(EmpTransHandleServiceImpl.java:1151)
at com.xxx.impl.EmpTransHandleServiceImpl.processBatchSubmitReceipt(EmpTransHandleServiceImpl.java:1077)
at com.xxx.impl.EmpTransHandleServiceImpl.submitTransReceipts(EmpTransHandleServiceImpl.java:156)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

2. Solution

After careful troubleshooting, it was found that a new getXXX() method was recently added to the object that needed to print logs. The method was used to process the fields in the existing object. Example:

public Integer getDutyLevelNumber() {
    String numberStr = dutyLevel.startsWith("M")
                ? dutyLevel.replace(BusConstants.M_DUTY_LEVEL_PREFIX, StringUtils.EMPTY)
                : dutyLevel.replace(BusConstants.P_DUTY_LEVEL_PREFIX, StringUtils.EMPTY);
        return Integer.valueOf(numberStr);
}

According to documentation, when Fastjson is serialized, the getXXX() method of the object is automatically executed by default. In addition, the validity of the field is not checked in advance within the method. Therefore, whenFastjson automatically executes the method, an internal NPE error occurs because the field is null.

With the reason identified, the solution is simple. Since Fastjson automatically executes the getXXX() method, renaming the method can solve the problem. Simply replace "getDutyLevelNumber()" with "fetchDutyLevelNumber()". After modification, the program is verified to run as expected.

Although the problem is solved, some questions still remain. Why does Fastjson automatically execute the getXXX() method? What is the whole serialization process of Fastjson? Since Fastjson is frequently used in daily development, it is necessary for us to thoroughly understand its inner workings.

3. Serialization Process

Talk is cheap. Show me the code.

In this section, we combine the Fastjson 1.2.76 source code and start from the toJSONString method to briefly analyze its serialization process.

3.1 JSON#toJSONString

public static String toJSONString(Object object, int defaultFeatures, SerializerFeature... features) {
    SerializeWriter out = new SerializeWriter((Writer) null, defaultFeatures, features);

    try {
        JSONSerializer serializer = new JSONSerializer(out);
        serializer.write(object);
        String outString = out.toString();
        int len = outString.length();
        if (len > 0
            && outString.charAt(len -1) == '.'
            && object instanceof Number
            && !out.isEnabled(SerializerFeature.WriteClassName)) {
            return outString.substring(0, len - 1);
        }
        return outString;
    } finally {
        out.close();
    }
}

First, the method creates a SerializeWriter object to write the serialized character stream to an internal buffer. Next, create a JSONSerializer object and pass the SerializeWriter object to it as a parameter. The JSONSerializer class is responsible for managing the serialization process and calling the appropriate serializer to convert a Java object into a JSON string. Then, serialization is performed by calling the write method of the JSONSerializer object.

3.2 JSONSerializer#write

public final void write(Object object) {
if (object == null) {
    out.writeNull();
    return;
}

Class<?> clazz = object.getClass();
ObjectSerializer writer = getObjectWriter(clazz);

try {
    writer.write(this, object, null, null, 0);
} catch (IOException e) {
    throw new JSONException(e.getMessage(), e);
}
}

Obtain the corresponding serializer (ObjectSerializer) based on the Class object from the SerializeConfig. Then, call the serializer's write method to serialize the object into a JSON string. The difference lies in getObjectWriter. ObjectSerializer is defined as an abstract interface and different objects will get different types of ObjectSerializer. Our code contains a custom object. Let's see how the custom object returns the ObjectSerializer.

3.3 SerializeConfig#getObjectWriter

public ObjectSerializer getObjectWriter(Class<?> clazz, boolean create) {
    ObjectSerializer writer = get(clazz);

    if (writer != null) {
        return writer;
    }
        ...
    if (writer == null) {
        String className = clazz.getName();
        Class<?> superClass;
        if (Map.class.isAssignableFrom(clazz)) {
            put(clazz, writer = MapSerializer.instance);
        } else if (List.class.isAssignableFrom(clazz)) {
            put(clazz, writer = ListSerializer.instance);
        } else if (Collection.class.isAssignableFrom(clazz)) {
            ...
        }
        if (create) {
                writer = createJavaBeanSerializer(clazz);
                put(clazz, writer);
        }
        ...
    }
   return writer;
}

First, find the ObjectSerializer from the cache. If it is not in the cache, obtain a specific serializer based on the clazz, such as Map and List. If no suitable serializer is found, proceed to create a JavaBeanSerializer. JavaBeanSerializer is a serializer for custom objects. You need to create a corresponding serializer for different objects. After creation, place it in the cache.

3.4 SerializeConfig#createJavaBeanSerializer

    public final ObjectSerializer createJavaBeanSerializer(Class<?> clazz) {
        String className = clazz.getName();
        long hashCode64 = TypeUtils.fnv1a_64(className);
      if (Arrays.binarySearch(denyClasses, hashCode64) >= 0) {
          throw new JSONException("not support class : " + className);
        }

      SerializeBeanInfo beanInfo = TypeUtils.buildBeanInfo(clazz, null, propertyNamingStrategy, fieldBased);
      if (beanInfo.fields.length == 0 && Iterable.class.isAssignableFrom(clazz)) {
          return MiscCodec.instance;
      }

      return createJavaBeanSerializer(beanInfo);
  }

This method has two main steps. The first step is to build the bean information object SerializeBeanInfo that needs to be serialized based on the clazz information, and the second step is to create the JavaBeanSerializer based on the SerializeBeanInfo. The SerializeBeanInfo contains all the field information that needs to be serialized in an object, that is, fields that need to be serialized are determined in the process of building the object. The creation of the JavaBeanSerializer will not be detailed here. Based on the confirmed fields that need to be serialized in the SerializeBeanInfo object, it makes a layer of encapsulation in combination with the serialization configuration of different fields.

3.5 TypeUtils#buildBeanInfo

    public static SerializeBeanInfo buildBeanInfo(Class<?> beanType //
            , Map<String,String> aliasMap //
            , PropertyNamingStrategy propertyNamingStrategy //
            , boolean fieldBased //
    ){
        Map<String,Field> fieldCacheMap = new HashMap<String,Field>();
        ParserConfig.parserAllFieldToCache(beanType, fieldCacheMap);
        List<FieldInfo> fieldInfoList = fieldBased
                ? computeGettersWithFieldBase(beanType, aliasMap, false, propertyNamingStrategy) //
                : computeGetters(beanType, jsonType, aliasMap, fieldCacheMap, false, propertyNamingStrategy);
        FieldInfo[] fields = new FieldInfo[fieldInfoList.size()];
        fieldInfoList.toArray(fields);
        ...
        return new SerializeBeanInfo(beanType, jsonType, typeName, typeKey, features, fields, sortedFields);
    }

The key point of this method is the retrieval of the fields. These fields represent the actual information that needs to be serialized. You can obtain information about all fields that correspond to the clazz through the computeGetters method. The fieldCacheMap is used to store the mappings between fieldNames and Fields, reducing the subsequent polling for findFields.

3.6 TypeUtils#computeGetters

    public static List<FieldInfo> computeGetters(Class<?> clazz, //
                                                 JSONType jsonType, //
                                                 Map<String,String> aliasMap, //
                                                 Map<String,Field> fieldCacheMap, //
                                                 boolean sorted, //
                                                 PropertyNamingStrategy propertyNamingStrategy //
    ){
        Map<String,FieldInfo> fieldInfoMap = new LinkedHashMap<String,FieldInfo>();
        boolean kotlin = TypeUtils.isKotlin(clazz);
        // for kotlin
        Constructor[] constructors = null;
        Annotation[][] paramAnnotationArrays = null;
        String[] paramNames = null;
        short[] paramNameMapping = null;
        Method[] methods = clazz.getMethods();
        for(Method method : methods) {
           if(methodName.startsWith("get")){
             if (methodName.length() < 4) {
                    continue;
             }
             ...
             else {
                 propertyName = methodName.substring(3);
                 field = ParserConfig.getFieldFromCache(propertyName, fieldCacheMap);
                 if (field == null) {
                    continue;
                 }
             }
            ...
            FieldInfo fieldInfo = new FieldInfo(propertyName, method, field, clazz, null, ordinal, serialzeFeatures, parserFeatures,
                        annotation, fieldAnnotation, label);
            fieldInfoMap.put(propertyName, fieldInfo);
        }
           if(methodName.startsWith("is")) {...}
        Field[] fields = clazz.getFields();
        computeFields(clazz, aliasMap, propertyNamingStrategy, fieldInfoMap, fields);
        return getFieldInfos(clazz, sorted, fieldInfoMap);
    }

The main function of this method is to parse the field information in the object and generate FiledInfo. First, obtain all methods of the object and loop through each method to determine whether the method starts with get or is, and if it does, make further judgment. Extract the characters after get or is as the field name to build a FieldInfo object, which includes information such as the name of the property, serialization method, and method.

Through the analysis of the computeGetters method, we can learn that the get method in the object is generally parsed into specific fields in Fastjson. For example, the getDutyLevelNumber method in the example is parsed into the dutyLevelNumber field.

The subsequent code flow will not be detailed further. It can be summarized as follows: the write method in the JavaBeanSerializer is executed. In this method, FieldInfos is looped through. For each field, its FieldSerializer is called for field serialization. Before serialization, the method object in the FieldInfo executes the invoke method to obtain the property value. Therefore, in this step, the getDutyLevelNumber method in the example is triggered, resulting in a system error.

Why is the getter method used to obtain the corresponding property?

At this point, you may wonder why Fastjson uses the getter method to obtain the corresponding property by default. It is also feasible to directly access fields, like Gson does.

First of all, this method complies with the Java Beans specification and is compatible with most Java classes. Secondly, obtaining property values through the getter method is relatively safer and provides encapsulation. For instance, if a field in the object contains sensitive information that should only be serialized or logged under certain conditions, you can add validation checks within the getter method. In addition, this method is flexible to a certain degree. If the field needs to be processed, it can also be done in the getter method without changing the original field value.

However, there are some shortcomings in this method. Firstly, the user is easy to meet errors. For example, the NPE problem encountered in this article is also due to the fact that the principle of Fastjson serialization is not clear at first, and the getter method is automatically executed, leading to the error. This kind of situation should account for the majority. Secondly, compared with direct access to fields, method calls may introduce slight performance loss, but this loss is generally negligible compared with the performance improvement of Fastjson using ASM technology.

4. Summary

For the problem of custom get methods being automatically executed by Fastjson, you can use the following methods:

  1. Change the prefix of the method name instead of using the get prefix. For example, replace the prefix with fetch.
  2. When calling the toJSONString method, specify additional parameters to ignore get methods that do not have corresponding fields. SerializerFeature.IgnoreNonFieldGetter
  3. In the get method, add the Fastjson annotation and ignore the serialization of this method. @JSONField(serialize = false).
  4. Add a JSON tool class to the project, define the toJSONString method in the tool class, and call Fastjson to catch errors. Converge JSON.toJSONString in the project into the tool class to avoid calling Fastjson directly.

Note that if you customize the get method, you should also try to avoid updating data in the get method. In addition, when processing fields inside the get method, you should check the validity of fields first to avoid abnormal situations such as NPE or the array index out-of-bounds error.


Disclaimer: The views expressed herein are for reference only and don't necessarily represent the official views of Alibaba Cloud.

0 0 0
Share on

Alibaba Cloud Community

1,046 posts | 257 followers

You may also like

Comments