记一次远程API调用失败

最近开发忙,项目紧,系统出现一些忽隐忽现的问题,本地也不能复现,当时也无法理解,就先搁置了,现在回想起来,这里还是明智的。

这个bug很神奇


今天,原本好好的API,突然抽风爆出数据转换异常,看看异常信息,指向一个远程调用API response json转换异常

2020-04-09 15:12:57.236 DEBUG 22236 --- [http-nio-9010-exec-2] c.l.framework.remote.crm.CrmRemoteApi    : [CrmRemoteApi#getProviderType] ---> POST http://micro-service-crm/remote/provider/type/list HTTP/1.1
2020-04-09 15:13:02.336 DEBUG 22236 --- [http-nio-9010-exec-5] c.l.framework.remote.crm.CrmRemoteApi    : [CrmRemoteApi#getProviderType] <--- HTTP/1.1 200 (5133ms)
2020-04-09 15:13:02.339 ERROR 22236 --- [http-nio-9010-exec-5] c.l.f.exception.GlobleExceptionHandler   : Exception:Error while extracting response for type [java.util.List<com.lansen.framework.dto.provider.CrmMaterialInfoPartnerEntity>] and content type [application/json;charset=utf-8]; nested exception is org.springframework.http.converter.HttpMessageNotReadableException: JSON parse error: Cannot deserialize instance of `java.util.ArrayList` out of START_OBJECT token; nested exception is com.fasterxml.jackson.databind.exc.MismatchedInputException: Cannot deserialize instance of `java.util.ArrayList` out of START_OBJECT token
 at [Source: (PushbackInputStream); line: 1, column: 1]

feign.codec.DecodeException: Error while extracting response for type [java.util.List<com.lansen.framework.dto.provider.CrmMaterialInfoPartnerEntity>] and content type [application/json;charset=utf-8]; nested exception is org.springframework.http.converter.HttpMessageNotReadableException: JSON parse error: Cannot deserialize instance of `java.util.ArrayList` out of START_OBJECT token; nested exception is com.fasterxml.jackson.databind.exc.MismatchedInputException: Cannot deserialize instance of `java.util.ArrayList` out of START_OBJECT token
 at [Source: (PushbackInputStream); line: 1, column: 1]
    at feign.SynchronousMethodHandler.decode(SynchronousMethodHandler.java:180)
    at feign.SynchronousMethodHandler.executeAndDecode(SynchronousMethodHandler.java:140)
    at feign.SynchronousMethodHandler.invoke(SynchronousMethodHandler.java:78)
    at feign.ReflectiveFeign$FeignInvocationHandler.invoke(ReflectiveFeign.java:103)
    at com.sun.proxy.$Proxy213.getProviderType(Unknown Source)

,这个问题应该不难,看了一下异常远程API


    @Override
    public List<Map<String, String>> getProviderType(List<String> materialNos) {
        return crmMaterialInfoPartnerService.getProviderType(materialNos);
    }

看代码返回值不符合开发规范(开发规范返回值不能使用Map,必须是具体实体类),找了一下负责这个模块功能的开发者“乐宝”(乐宝是我们项目组的一位呆萌男孩,是个态度和工作都很努力的大眼小伙儿,遇到问题总是眼睛瞳孔放大,眼神一片迷茫还伴随着不断点头,总之非常可爱),简单讲解了一下异常信息,把这个问题交给“乐宝”解决。下午的时候找到乐宝,问了一下修复情况,乐宝还是一头雾水,看我过来了,试探问是不是我这个返回实体有包含自己的情况

public class CrmMaterialInfoPartnerEntity extends BaseEntity {
    @TableField(exist = false)
    List<CrmMaterialInfoPartnerEntity> materialList;
}

想到这点,他赶紧删掉测了一圈,问题还是一样,由于时间紧,这块儿自引用先按下不表,叮嘱乐宝先尝试解决,不行就换一种写法试试,经过了几轮儿排查,不知不觉已经是下午6点了,乐宝说改好了,代码提交开始发测试版本,版本发完测试验证问题依然存在,乐宝本地验证没问题,不过他发现第一次是正常的,清理了redis,问题就出现了,这问题奇怪了,怎么会跟redis有关系呢,顿时陷入了沉思中...


这个bug很调皮

乐宝说返回List集合的接口都有问题,他已经修复了2个模块了,测试后仍然报错,找不到问题的原因,先让乐宝保留本地修改的代码,暂不提交。我开始盯着代码思考这个问题,一般这种转换异常的问题,要么是返回值映射有问题,要么是传参映射有问题,顺着这两个思路我打开了debug模式,A服务远程调用B服务,先检查B服务有没有接收到请求,排查B服务收到了请求,但是B服务还未响应请求,A服务突然报错了what???......
沉思中时,老大哥也过来帮忙排查,我俩简单同步问题信息后,定位到gateway的feign调用超时问题,开始修改配置,把超时时间设置大些,把redis超时时间也调大,正在尝试测试时,另一个项目组也模拟出一种偶现问题,调用远程API时提示强制退出登录,这是什么情况?猜测两个问题应该来源一个出处,为什么远程API会跟redis有关系呢?于是过去看了一下强制退出登录的问题,也没摸到头绪,回来时老大哥模拟出来一种新思路,服务刚启动时清空redis问题会出现,这时候把远程服务重启,再次清理redis发现问题没有了,重新整理思路,代码开始在脑子里浮现,每一个服务都有一个权限认证拦截器,只有这里使用到了redis,难道是这里出现的问题?废话不多说,开始在这里debug,一番排查后,发现远程服务验证token时候出错了,根据报错信息还是很难分辨出为什么异常,老大哥提出我们在这里打一下token看一下调用时候token有什么问题,


2020-04-09 18:53:33.913 DEBUG 15880 --- [http-nio-9002-exec-2] c.l.f.web.filter.BaseInterceptor         : 当前访问URL:/remote/provider/type/list,
redis  token: eyJhbGciOiJIUzI1NiJ9.eyJqdGkiOiJkMWMyNzExNC1mZmU2LTQ0MTktODMzNC1hNjQwNjQ5YTYwODQiLCJpc3MiOiJKV1QiLCJzdWIiOiJ7XCJ1c2VySWRcIjpcImQ3YzNlNmY0NGMwMmUxMmM2NTVjOGRmM2NhZDM3MDFkXCIsXCJ1c2VyTmFtZVwiOlwiYW5kZXJzXCIsXCJ0eXBlXCI6XCJhY2NvdW50XCIsXCJhcHBsaWNhdGlvbklkXCI6XCJiMmFlZmNhMmI4YjA0YzJiYTEyZGYwY2JlZTkwdDJjZVwiLFwidGltZVwiOjE1ODY0Mjk1NjgzMzB9IiwiaWF0IjoxNTg2NDI5NTY4LCJleHAiOjE1ODcwMzQzNjh9.uvWNCUZR9JucS5aBdKdNui8bPxXVlXW_-wD1-pbt4rI 
remote token: eyJhbGciOiJIUzI1NiJ9.eyJqdGkiOiJjMjQ0MmZjYy1mM2QxLTRjMzEtOTc5Yi00NDlhNTg4ZTRmMjMiLCJpc3MiOiJKV1QiLCJzdWIiOiJ7XCJ1c2VySWRcIjpcImQ3YzNlNmY0NGMwMmUxMmM2NTVjOGRmM2NhZDM3MDFkXCIsXCJ1c2VyTmFtZVwiOlwiYW5kZXJzXCIsXCJ0eXBlXCI6XCJhY2NvdW50XCIsXCJhcHBsaWNhdGlvbklkXCI6XCJiMmFlZmNhMmI4YjA0YzJiYTEyZGYwY2JlZTkwdDJjZVwiLFwidGltZVwiOjE1ODY0MzA1NTI2MTh9IiwiaWF0IjoxNTg2NDMwNTUyLCJleHAiOjE1ODcwMzUzNTJ9.SdqEVuVfUn7oPOoYZmVTwugONbfg8Vy12W2ffpNqdnM

两次token不一致,why???

只有远程API调用的时候token不一致,检查了一遍认证拦截器,没有发现异常问题,突然想到了远程API的feign拦截器,打开代码一看,恍然大悟,就是这里了

    @Override
    public void apply(RequestTemplate requestTemplate) {
        FeignRequestContext feignRequestContext = FeignRequestContextLocal.getInstance().get();
        if (Objects.nonNull(feignRequestContext)) {
            requestTemplate.headers(feignRequestContext.buildHeaders());
        }else if(Objects.nonNull(CommonUtils.getRequest())) {
            requestTemplate.headers(getHeads(CommonUtils.getRequest()));
        }
    }
    private Map<String, Collection<String>> getHeads(HttpServletRequest request) {
        FeignRequestContext feignRequestContext = new FeignRequestContext(request);
        FeignRequestContextLocal.getInstance().set(feignRequestContext);
        return feignRequestContext.buildHeaders();
    }

由于有异步处理的业务场景,这里使用了线程变量存储远程上下文参数,这里没有考虑到清理,去掉这里的线程变量,程序运行舒畅了,到此问题圆满解决了,真是一场深刻的bug排查。


最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
平台声明:文章内容(如有图片或视频亦包括在内)由作者上传并发布,文章内容仅代表作者本人观点,简书系信息发布平台,仅提供信息存储服务。

推荐阅读更多精彩内容

  • 包含的重点内容:JAVA基础JVM 知识开源框架知识操作系统多线程TCP 与 HTTP架构设计与分布式算法数据库知...
    消失er阅读 4,395评论 1 10
  • TCP 与 HTTP http1.0 和 http1.1 有什么区别。 HTTP 1.0主要有以下几点变化: 请求...
    冷枫abc阅读 508评论 0 0
  • 我们活着的意义?就是把无量的财富和圆满的智慧与整个宇宙共同分享…… 分享就是给出去…… 给出去就是带给一切生命真正...
    王涤飞阅读 506评论 0 3
  • 平江记忆,我漫步在淅淅沥沥的小雨中,享受着这片美丽。小桥,流水,人家,这片土地带给我的不仅仅是一份宁静,还有向往的...
    字母ge阅读 160评论 0 2
  • 像是蒙着眼睛 跳进深深的湖里 周围的人们 是泛起的涟漪 而你们 是咕噜咕噜上升的气泡 证明 我还活着
    mozik阅读 443评论 0 2