记一次问题排查

背景：做了一个定时job的需求，本地测试没有问题，上线后发现定时job执行超时，询问相关人员，说是调用下游服务失败，经查看代码，发现逻辑中确实调用了下游服务

排查过程：

1.本地可以正常run，但是上到测试环境有问题，第一个思路是：是不是本地和测试环境的环境变量不一致导致的？

于是仔细对比了本地和测试环境，发现没有区别

2.开启debug模式，发现在debug的过程中，在第一次调用下游服务的时候，偶现可以拿到数据，但基本上拿不到数据，且client报NPE，于是一直在排查为啥没有拿到数据，没有结果

本地去调用第三方服务，相同的参数完全可以拿到数据，到底是为什么呢？

3.debug无果后，直接看日志信息，通过日志发现，在调用下游服务时，第二次拿到的结果为空，那是不是下游服务没有返回？查看了下游服务的日志，发现两次请求都返回了，但是服务能拿到第一次返回结果，拿不到第二次返回结果，且日志中报出了中断异常

4.第一反应中断异常是不是由于线程问题导致的？且从日志中可以看到调用下游的接口是报了Unkown Source，所以当时严重怀疑是线程问题，于是在第二次调用下游服务的时候进行了sleep，但发现解决不了问题

5.最后经过排查发现日志：

com.xxl.job.core.thread.JobThread，这一行日志表示线程池是有超时控制的，既然有超时，那调整下超时时间，果然成功了！！

为什么排查那么久？

1.debug过程中发现client NPE ，误以为问题一定是出现在调用下游服务有问题，且这个NPE让人以为是没有拿到bean，导致无法正常获取数据，在这块上耗费了不少时间

2.有对线程问题进行过怀疑，毕竟报出了中断异常，但一直考虑的是不是两次rpc调用的时候出现问题，导致第二次调用rpc被中断，还是围绕rpc来排查问题

解决和反思：

专注于最初的日志，其实日志中已经报出来是中断异常，但是当时想到的是线程控制，应该可以看到更下沉的日志信息，这样就可以很清楚的看到是定时job超时导致的问题