一行日志引发的系统异常

本文涉及的产品
日志服务 SLS,月写入数据量 50GB 1个月
简介: 本文记录了一行日志引发的系统异常以及作者解决问题的思路。

一、发现问题

在一次迭代开发过程中,新增了一行日志打印,导致系统主流程出现了异常。当时在想为何如此诡异,一行日志竟引发了 BUG。


新增的日志打印代码:


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

下面是当时的错误日志截图:

image.png

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)

二、解决问题

经过仔细排查,发现需要打印日志的对象中,近期新增了一个 getXXX() 方法,用于对现有对象中的字段进行加工处理。如下:

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);
}

查阅资料了解到,fastjson 进行序列化时,默认会自动执行对象的 getXXX() 方法。又由于该方法内部没有对字段合法性进行提前校验,因此当 fastjson 自动执行该方法时,由于字段为 null,导致了内部出现了 NPE 异常。


知道原因之后,解决问题的方式很简单。既然 fastjson 会自动执行 getXXX() 方法,那么修改方法命名不就可以了么。直接将 「getDutyLevelNumber()」替换为 「fetchDutyLevelNumber()」,修改后验证程序正常。


虽然问题得以解决,但还是有些疑问摆在我们面前,为何 fastjson 会自动执行 getXXX() 方法?fastjson 整个序列化过程是大概怎样的?由于 fastjson 在日常开发过程中使用比较频繁,我们有必要把其中的来龙去脉探究清楚。


三、序列化过程

Talk is cheap. Show me the code

下面我们结合 fastjson 1.2.76 源码,从 toJSONString 方法出发,简要分析下它的序列化过程。


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();
    }
}

首先,方法创建了一个 SerializeWriter 对象,用于将序列化后的字符流写入一个内部缓冲区。接下来,创建一个 JSONSerializer 对象,并将SerializeWriter对象作为参数传递给它。JSONSerializer 类负责管理序列化过程,并调用合适的序列化器将 Java 对象转换为 JSON 字符串。然后,通过调用 JSONSerializer 对象的 write 方法进行序列化。


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);
}
}

根据Class对象从SerializeConfig中获取对应的序列化器(ObjectSerializer)。接着调用序列化器的write方法将对象序列化为JSON字符串。区别点在于 getObjectWriter,ObjectSerializer 被定义成一个抽象接口,不同的对象会获取到不同类型的 ObjectSerializer。我们代码中是自定义的对象,看下自定义对象是如何返回 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;
}

先从缓存中找到ObjectSerializer,缓存中没有则先根据clazz获取特定的序列化器,比如Map、List这些,没有的话,则进入到创建JavaBeanSerializer的流程中。JavaBeanSerializer是自定义对象的序列化器,不同对象都需要创建一个对应的序列化器。创建完成后再放入缓存中。


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);
  }

这个方法主要有两步,第一步根据 clazz 信息构建需要序列化的 bean 信息对象 SerializeBeanInfo,第二步根据 SerializeBeanInfo 创建 JavaBeanSerializer。SerializeBeanInfo 中包含了一个对象中需要序列化的所有字段信息,也就是说哪些字段需要进行序列化就是在构建该对象的过程中进行判断的。创建 JavaBeanSerializer 的细节这里先不展开,主要是根据 SerializeBeanInfo 对象中已经确认好的需要序列化的字段,再结合不同字段的序列化配置,做了一层封装。


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);
    }

关键点在于 fields 的获取,fields 字段就是真正需要序列化的字段信息。通过 computeGetters 方法获取对应 clazz 的所有字段信息。实现过程中借助了 fieldCacheMap 存储 fieldName 和 Field 的映射关系,减少之后的 findField 的轮询。


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);
    }

该方法主要作用是解析对象中的字段信息,并生成 FiledInfo 。首先获取对象的所有方法,对每个方法进行循环处理:判断方法是否以 get 或者 is 开头,如果是,则进一步判断。并取出 get 或者 is 之后的字符作为字段名称,构建 FieldInfo 对象,FieldInfo 中包括了属性的名称、序列化方法、方法等信息。



通过对 computeGetters 方法的分析,我们可以了解到对象中的 get 方法在 fastjson 中一般会被解析成具体的字段。比如,样例中的 getDutyLevelNumber 方法会被解析成 dutyLevelNumber 字段。


后续的代码流程不再展开,简单概括下:最终会执行 JavaBeanSerializer 中的 write 方法,该方法内部实际上会对 FieldInfos 进行循环处理,针对每个 field,会调用它的 FieldSerializer 进行字段序列化。序列化之前会通过 FieldInfo 中的 method 对象执行 invoke 方法获取属性值。因此在这一步会触发样例中的 getDutyLevelNumber 方法执行,导致系统异常。


为何通过 getter 方法获取对应的属性?

分析至此,我们可能会想,fastjson 为何默认使用 getter 方法获取对应的属性?直接访问字段不也可以吗,比如 Gson 就是这样做的。



我的理解,首先这种方式是遵循 Java Beans 规范的,也能够兼容绝大多数 Java 类。其次,通过 getter 获取属性值相对来说更安全且具有一定的封装性,试想下如果对象中某个字段信息比较敏感,需要符合一定条件才允许序列化传输或者打印日志,我们在 getter 方法中增加卡控判断即可。另外,这种方式也具备一定的灵活性,如果需要对字段进行加工,也可在 getter 方法中进行处理,而无需改变原先的字段值。



但这种方式也存在一些不足。一是,使用者容易踩坑。比如本文遇到的 NPE 问题,也是因为起初不清楚 fastjson 序列化的原理,会自动执行 getter 方法,从而踩了坑,此类情况应该占多数;二是,性能开销,相比于直接访问字段,通过方法调用可能引入轻微的性能损耗,不过这点损耗,一般情况下相较于 fastjson 使用 ASM 技术提升的性能,可忽略不计。


四、实践总结

针对自定义的 get 方法会被 fastjson 自动执行的情况,一般有以下几种方式可以解决。


1.调整方法名称的前缀,不使用 get 前缀,比如换成 fetch。

2.调用 toJSONString 方法时,额外指定参数忽略没有对应字段的 get 方法。

SerializerFeature.IgnoreNonFieldGetter3.在 get 方法上增加 fastjson 的注解,忽略此方法的序列化。@JSONField(serialize = false)。

4.在项目中增加 JSON 工具类,工具类中定义 toJSONString 方法并且调用 fastjson,并捕获异常。将项目中的 JSON.toJSONString 都收敛到工具类中,避免直接调用 fastjson。



另外也需注意,如果自定义 get 方法,也要尽量避免在 get 方法中进行数据更新操作。同时在 get 方法内部对字段进行处理时,养成先对字段合法性校验的编码习惯,避免产生 NPE 或数组越界等异常情况。








来源  |  阿里云开发者公众号

作者  |  八帆

相关实践学习
日志服务之使用Nginx模式采集日志
本文介绍如何通过日志服务控制台创建Nginx模式的Logtail配置快速采集Nginx日志并进行多维度分析。
目录
打赏
0
11
11
0
2718
分享
相关文章
Grafana Loki,轻量级日志系统
本文介绍了基于Grafana、Loki和Alloy构建的轻量级日志系统。Loki是一个由Grafana Labs开发的日志聚合系统,具备高可用性和多租户支持,专注于日志而非指标,通过标签索引而非内容索引实现高效存储。Alloy则是用于收集和转发日志至Loki的强大工具。文章详细描述了系统的架构、组件及其工作流程,并提供了快速搭建指南,包括准备步骤、部署命令及验证方法。此外,还展示了如何使用Grafana查看日志,以及一些基本的LogQL查询示例。最后,作者探讨了Loki架构的独特之处,提出了“巨型单体模块化”的概念,即一个应用既可单体部署也可分布式部署,整体协同实现全部功能。
524 69
Grafana Loki,轻量级日志系统
MiniMax GenAI 可观测性分析 :基于阿里云 SelectDB 构建 PB 级别日志系统
基于阿里云SelectDB,MiniMax构建了覆盖国内及海外业务的日志可观测中台,总体数据规模超过数PB,日均新增日志写入量达数百TB。系统在P95分位查询场景下的响应时间小于3秒,峰值时刻实现了超过10GB/s的读写吞吐。通过存算分离、高压缩比算法和单副本热缓存等技术手段,MiniMax在优化性能的同时显著降低了建设成本,计算资源用量降低40%,热数据存储用量降低50%,为未来业务的高速发展和技术演进奠定了坚实基础。
MiniMax GenAI 可观测性分析 :基于阿里云 SelectDB 构建 PB 级别日志系统
PHP 日志系统的最佳搭档:一个 Go 写的远程日志收集服务
为了不再 SSH 上去翻日志,我写了个 Go 小脚本,用来接收远程日志。PHP 负责记录日志,Go 负责存储和展示,按天存储、支持 API 访问、可远程管理,终于能第一时间知道项目炸了。
31 10
【YashanDB知识库】yasdb jdbc驱动集成druid连接池,业务(java)日志中有token IDENTIFIER start异常
客户Java日志中出现异常,影响Druid的merge SQL功能(将SQL字面量替换为绑定变量以统计性能),但不影响正常业务流程。原因是Druid在merge SQL时传入null作为dbType,导致无法解析递归查询中的`start`关键字。
Spring Boot 3 集成Spring AOP实现系统日志记录
本文介绍了如何在Spring Boot 3中集成Spring AOP实现系统日志记录功能。通过定义`SysLog`注解和配置相应的AOP切面,可以在方法执行前后自动记录日志信息,包括操作的开始时间、结束时间、请求参数、返回结果、异常信息等,并将这些信息保存到数据库中。此外,还使用了`ThreadLocal`变量来存储每个线程独立的日志数据,确保线程安全。文中还展示了项目实战中的部分代码片段,以及基于Spring Boot 3 + Vue 3构建的快速开发框架的简介与内置功能列表。此框架结合了当前主流技术栈,提供了用户管理、权限控制、接口文档自动生成等多项实用特性。
119 8
写了BUG还想跑——闲鱼异常日志问题自动追踪-定位-分发机制
为了高效地发现、定位和解决预发问题,闲鱼团队研发了一套异常日志问题自动追踪-定位-分发机制。这套机制通过自动化手段,实现了异常日志的定时扫描、精准定位和自动分发,显著降低了开发和测试的成本,提高了问题解决的效率。
228 15
写了BUG还想跑——闲鱼异常日志问题自动追踪-定位-分发机制
什么是事件日志管理系统?事件日志管理系统有哪些用处?
事件日志管理系统是IT安全的重要工具,用于集中收集、分析和解释来自组织IT基础设施各组件的事件日志,如防火墙、路由器、交换机等,帮助提升网络安全、实现主动威胁检测和促进合规性。系统支持多种日志类型,包括Windows事件日志、Syslog日志和应用程序日志,通过实时监测、告警及可视化分析,为企业提供强大的安全保障。然而,实施过程中也面临数据量大、日志管理和分析复杂等挑战。EventLog Analyzer作为一款高效工具,不仅提供实时监测与告警、可视化分析和报告功能,还支持多种合规性报告,帮助企业克服挑战,提升网络安全水平。
143 2
centos系统清理docker日志文件
通过以上方法,可以有效清理和管理CentOS系统中的Docker日志文件,防止日志文件占用过多磁盘空间。选择合适的方法取决于具体的应用场景和需求,可以结合手动清理、logrotate和调整日志驱动等多种方式,确保系统的高效运行。
424 2
解决 Java 打印日志吞异常堆栈的问题
前几天有同学找我查一个空指针问题,Java 打印日志时,异常堆栈信息被吞了,导致定位不到出问题的地方。
90 2
|
5月前
|
告别简陋:Java日志系统的最佳实践
【10月更文挑战第19天】 在Java开发中,`System.out.println()` 是最基本的输出方法,但它在实际项目中往往被认为是不专业和不足够的。本文将探讨为什么在现代Java应用中应该避免使用 `System.out.println()`,并介绍几种更先进的日志解决方案。
120 1

热门文章

最新文章

AI助理

你好,我是AI助理

可以解答问题、推荐解决方案等