生产环境一次诡异的NPE问题,反转了4次

前言

公司为了保证系统的稳定性,加了很多监控,比如:接口响应时间、cpu使用率、内存使用率、错误日志等等。如果系统出现异常情况,会邮件通知相关人员,以便于大家能在第一时间解决隐藏的系统问题。此外,我们这边有个不成文的规定,就是线上问题最好能够当日解决,除非遇到那种非常棘手的问题。

1.起因

有个周一的早上,我去公司上班,查看邮件,收到我们老大转发的一封邮件,让我追查线上的一个NPE(NullPointException)问题。

邮件是通过sentry发出来的,我们通过点击邮件中的相关链接,可以直接跳转到sentry的详情页面。在这个页面中,展示了很多关键信息,比如:操作时间、请求的接口、出错的代码位置、报错信息、请求经过了哪些链路等等。真是居家旅行,查bug的良药,有了这些,小case一眼就能查到原因。

我当时没费吹灰之力,就访问到了NPE的sentry报错页面(其实只用鼠标双击一下就搞定)。果然上面有很多关键信息,我一眼就看到了NPE的具体代码位置:

notify.setName(CurrentUser.getCurrent().getUserName());

剧情发展得如此顺利,我都有点不好意思了。

根据类名和代码行号,我在idea中很快找到那行代码,不像是我写的,这下可以放心不用背锅了。于是接下来看了看那行的代码修改记录,最后修改人是XXX。

什么?是他?

他在一个月前已经离职了,看来这个无头公案已经无从问起,只能自己查原因。

我当时内心的OS是:代码没做兼容处理

为什么这么说呢?

这行代码其实很简单,就是从当前用户上下文中获取用户名称,然后设置到notify实体的inUserName字段上,最终notify的数据会保存到数据库。

该字段表示那条推送通知的添加人,正常情况下没啥卵用,主要是为了出现线上问题扯皮时,有个地方可以溯源。如果出现冤案,可以还你清白。

顺便提一嘴,这里说的推送通知跟mq中的消息是两回事,前者指的是websocket长连接推送的实时通知,我们这边很多业务场景,在页面功能操作完之后,会实时推送通知给指定用户,以便用户能够及时处理相关单据,比如:您有一个审批单需要审批,请及时处理等。

CurrentUser内部包含了一个ThreadLocal对象,它负责保存当前线程的用户上下文信息。当然为了保证在线程池中,也能从用户上下文中获取到正确的用户信息,这里用了阿里的TransmittableThreadLocal。伪代码如下:

@Data
public class CurrentUser {private static final TransmittableThreadLocal<CurrentUser> THREA_LOCAL = new TransmittableThreadLocal<>();private String id;private String userName;private String password;private String phone;...public statis void set(CurrentUser user) {THREA_LOCAL.set(user);}public static void getCurrent() {return THREA_LOCAL.get();}
}

这里为什么用了阿里的TransmittableThreadLocal,而不是普通的ThreadLocal呢?在线程池中,由于线程会被多次复用,导致从普通的ThreadLocal中无法获取正确的用户信息。父线程中的参数,没法传递给子线程,而TransmittableThreadLocal很好解决了这个问题。

然后在项目中定义一个全局的spring mvc拦截器,专门设置用户上下文到ThreadLocal中。伪代码如下:

public class UserInterceptor extends HandlerInterceptorAdapter {@Override  public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {CurrentUser user = getUser(request);if(Objects.nonNull(user)) {CurrentUser.set(user);}} 
}

用户在请求我们接口时,会先触发该拦截器,它会根据用户cookie中的token,调用调用接口获取redis中的用户信息。如果能获取到,说明用户已经登录,则把用户信息设置到CurrentUser类的ThreadLocal中。

接下来,在api服务的下层,即business层的方法中,就能轻松通过CurrentUser.getCurrent();方法获取到想要的用户上下文信息了。

这套用户体系的想法是很good的,但深入使用后,发现了一个小插曲:

api服务和mq消费者服务都引用了business层,business层中的方法两个服务都能直接调用。

我们都知道在api服务中用户是需要登录的,而mq消费者服务则不需要登录。

如果business中的某个方法刚开始是给api开发的,在方法深处使用了CurrentUser.getCurrent();获取用户上下文。但后来,某位新来的帅哥在mq消费者中也调用了那个方法,并未发觉这个小机关,就会中招,出现找不到用户上下文的问题。

所以我当时的第一个想法是:代码没做兼容处理,因为之前这类问题偶尔会发生一次。

想要解决这个问题,其实也很简单。只需先判断一下能否从CurrentUser中获取用户信息,如果不能,则取配置的系统用户信息。伪代码如下:

@Autowired
private BusinessConfig businessConfig;CurrentUser user = CurrentUser.getCurrent();
if(Objects.nonNull(user)) {entity.setUserId(user.getUserId());entity.setUserName(user.getUserName());
} else {entity.setUserId(businessConfig.getDefaultUserId());entity.setUserName(businessConfig.getDefaultUserName());
}

这种简单无公害的代码,如果只是在一两个地方加还OK。

但如果有多个地方都在获取用户信息,难道在每个地方都需要把相同的判断逻辑写一遍?对于有追求的程序员来说,这种简单的重复是写代码的大忌,如何更优雅的解决问题呢?

答案将会在文章后面揭晓。

这个NPE问题表面上,已经有答案了。根据以往的经验,由于在代码中没有做兼容处理,在mq消费者服务中获取到的用户信息为空,对一个空对象,调用它的方法,就会出现NPE。

2.第一次反转

但这个答案显得有点草率,会不会还有什么机关?

于是我在项目工程中全局搜索CurrentUser.set关键字,竟然真的找到了一个机关。

剧情出现第一次反转。

有个地方写了一个rocketmqAOP拦截器,伪代码如下:

@Aspect
@Component
public class RocketMqAspect {@Pointcut("execution(* onMessage(..)&&@within(org.apache.rocketmq.spring.annotation.RocketMQMessageListener))")public void pointcut() {}...@Around(value="pointcut")public void around(ProceedingJoinPoint point) throws Throwable {if(point.getArgs().length == 1 && point.getArgs()[0] instanceof MessageExt) {Message message = (Message)point.getArgs()[0];String userId = message.getUserProperty("userId");String userName = message.getUserProperty("userName");if(StringUtils.notEmpty(userId) && StringUtils.notEmpty(userName))  {CurrentUser user = new CurrentUser();user.setUserId(userId);user.setUserName(userName);CurrentUser.set(user);}}...}
}

它会拦截所有mq消费者中的onMessage方法,在该方法执行之前,从userProperty中获取用户信息,并且创建用户对象,设置到用户上下文中。

温馨提醒一下,免得有些朋友依葫芦画瓢踩坑。上面的伪代码只给出了设置用户上下文的关键代码,用完后,删除用户上下文的代码没有给出,感兴趣的朋友可以找我私聊。

既然有获取用户信息的地方,我猜测必定有设置的地方。这时候突然发现自己有点当侦探的潜力,因为后面还真找到了。

意不意外,惊不惊喜?

另外一个同事自己自定义了一个RocketMQTemplate。伪代码如下:

public class MyRocketMQTemplate extends RocketMQTemplate {@Overridepublic void asyncSend(String destnation, Meassage<?> message, SendCallback sendCallback, long timeout, int delayLevel) {MessageBuilder builder = withPayload(message.getPayLoad());CurrentUser user = CurrentUser.getCurrent();builder.setHeader("userId", user.getUserId());builder.setHeader("userName", user.getUserName());super.asyncSend(destnation,message,sendCallback,timeout,delayLevel);}
}

这段代码的主要作用是在mq生产者在发送异步消息之前,先将当前用户上下文信息设置到mq消息的header中,这样在mq消费者中就能通过userProperty获取到,它的本质也是从header中获取到的。

这个设计比较巧妙,完美的解决了mq的消费者中通过CurrentUser.getCurrent();无法获取用户信息的问题。

此时线索一下子断了,没有任何进展。

我再去查了一下服务器的日志。确认了那条有问题的mq消息,它的header信息中确实没有userId和userName字段。

莫非是mq生产者没有往header中塞用户信息?这是需要重点怀疑的地方。

因为mq生产者是另外一个团队写的代码,在EOA(签报系统)回调他们系统时,会给我们发mq消息,通知我们签报状态。

而EOA是第三方的系统,用户体系没有跟我们打通。所以在另外一个团队的回调接口中,没法获取当前登录的用户信息,AOP的拦截器就没法自动往header中塞用户信息,这样在mq的消费者中自然就获取不到了。

这样想来还真的是顺理成章。

3.第二次反转

但真的是这样的吗?

我们抱着很大的希望,给他们发了一封邮件,让他们帮忙查一下问题。

很快,他们回邮件了。

但他们说:已经本地测试过,功能正常。

就这样剧情第二次反转了。

我此时有点好奇,他们是怎么往header中塞用户信息的。带着“学习的心态”,于是找他们一起查看了相关代码。

他们在发送mq消息之前,会调用一个UserUtil工具注入用户。该工具类的伪代码如下:

@Component
public class UserUtil{@Value("${susan.userId}")private String userId;@Value("${susan.userName}")private String userName;public void injectUser() {CurrentUser user = new CurrentUser();user.setUserId(userId);user.setUserName(userName);CurrentUser.set(user);}
}

好吧,不得不承认,这样做确实可以解决header传入用户信息的问题,比之前需要手动判断用户信息是否为空要优雅得多,因为注入之后的用户信息肯定是不为空的。

折腾了半天,NPE问题还是没有着落。

我回头再仔细看了那个自定义的RocketMQTemplate类,发现里面重写的方法:asyncSend,它包含了5个参数。而他们在给我们推消息时,调用的asyncSend却只传了3个参数。

一下子,问题又有了新的进展,有没有可能是他们调错接口了?

原本应该调用5个参数的方法,但实际上他们调用了3个参数的方法。

这样就能解释通了。

4.第三次反转

终于有点思路,我带着一份喜悦,准备开始证明刚刚的猜测。

但事实证明,我真的高兴的太早了,马上被啪啪打脸。

这次是反转最快的一次。

怎么回事呢?

原本我以为是另外一个团队的人,在发mq消息时调错方法了,应该调用5个参数的asyncSend方法,但他们的代码中实际上调用的是3个参数的同名方法。

为了防止出现冤枉同事的事情发生。我本着尽职尽责的态度,仔细看了看RocketMQTemplate类的所有方法,这个类是rocketmq框架提供的。

意外发现了一些藕断丝连的关系,伪代码如下:

public void asyncSend(String destination, Message<?> message, SendCallback sendCallback, long timeout, int delayLevel) {if (Objects.isNull(message) || Objects.isNull(message.getPayload())) {log.error("asyncSend failed. destination:{}, message is null ", destination);throw new IllegalArgumentException("`message` and `message.payload` cannot be null");}try {org.apache.rocketmq.common.message.Message rocketMsg = RocketMQUtil.convertToRocketMessage(objectMapper,charset, destination, message);if (delayLevel > 0) {rocketMsg.setDelayTimeLevel(delayLevel);}producer.send(rocketMsg, sendCallback, timeout);} catch (Exception e) {log.info("asyncSend failed. destination:{}, message:{} ", destination, message);throw new MessagingException(e.getMessage(), e);}
}public void asyncSend(String destination, Message<?> message, SendCallback sendCallback, long timeout) {asyncSend(destination,message,sendCallback,timeout,0);
}public void asyncSend(String destination, Message<?> message, SendCallback sendCallback) {asyncSend(destination, message, sendCallback, producer.getSendMsgTimeout());
}public void asyncSend(String destination, Object payload, SendCallback sendCallback, long timeout) {Message<?> message = this.doConvert(payload, null, null);asyncSend(destination, message, sendCallback, timeout);
}public void asyncSend(String destination, Object payload, SendCallback sendCallback) {asyncSend(destination, payload, sendCallback, producer.getSendMsgTimeout());
}

这个背后隐藏着一个天大的秘密,这些同名的方法殊途同归,竟然最终都会调用5个参数的asyncSend方法。

这样看来,如果在子类中重写了5个的asyncSend方法,相当于重写了所有的asyncSend方法。再次证明他们没错。

温馨提醒一下,有些类的重载方法会相互调用,如果在子类中重新了最底层的那个重载方法,等于把所有的重载方法都重写了。

头疼,又要回到原点了。

5.第四次反转

此时,我有点迷茫了。

不过,有个好习惯是:遇到线上问题不知道怎办时,会多查一下日志。

本来不报啥希望的,但是没想到通过再查日志。

出现了第四次反转。

这次抱着试一下的心态,根据messageID去查了mq生产者的日志,查到了一条消息的发送日志。

这次眼睛擦得雪亮,发现了一个小细节:时间不对

这条日志显示的消息发送日期是2021-05-21,而实际上mq消费者处理的日期是2021-05-28。

这条消息一个星期才消费完?

显然不是。

我有点肃然起敬了。再回去用那个messageID查了mq消费者的日志,发现里面其实消费了6次消息。前5次竟然是同一天,都在2021-05-21,而且都处理失败了。另一次是2021-05-28,处理成功了。

为什么同一条消息,会在同一天消费5次?

如果你对rocketmq比较熟悉的话,肯定知道它支持重试机制。

如果mq消费者消息处理失败了,可以在业务代码中抛一个异常。然后框架层面捕获该异常返回ConsumeConcurrentlyStatus.RECONSUME_LATER,rocketmq会自动将该消息放到重试队列流程图如下:这样mq消费者下次可以重新消费那条消息,直到达到一定次数(这里我们配置的5次),rocketmq会将那条消息发送到死信队列流程图如下:后面就不再消费了。

最后为什么会多消费一次?

最后的那条消息不可能是其他的mq生产者发出的,因为messageID是唯一的,其他的生产者不可能产生一样的messageID。

那么接下来,只有一种可能,那就是人为发了条消息

查线上日志时,时间、messageID、traceID、记录条数 这几个维度至关重要。

6.真相

后来发现还真的是人为发的消息。

一周前,线上有个用户,由于EOA页面回调接口失败(重试也失败),导致审核状态变更失败。该审核单在EOA系统中审批通过了,但mq消费者去处理该审核单的时候,发现状态还是待审核,就直接返回了,没有走完后续的流程,从而导致该审核单数据数据异常。

为了修复这个问题,我们当时先修改了线上该审核单的状态。接下来,手动的在rocketmq后台发了条消息。由于当时在rocketmq后台看不到header信息,所以发消息时没有管header,直接往指定的topic中发消息了。

千万注意,大家在手动发mq消息时,一定要注意header中是否也需要设置相关参数,尤其是rocketmq,不然就可能会出问题。

mq消费者消费完那条消息之后,该审核单正常走完了流程,当时找测试一起测试过,数据库的状态都是正常的。

大家都以为没有问题了,但是所有人都忽略了一个小细节:就是在正常业务逻辑处理完之后,会发websocket通知给指定用户。但这个功能是已经离职的那个同事加的新逻辑,其他人都不知道。站在手动发消息的那个人的角度来说,他没错,因为他根本不知道新功能的存在。

由于这行代码是最后一行代码,并且跟之前的代码不在同一个事物当中,即使出了问题也不会影响正常的业务逻辑。

所以这个NPE问题影响范围很小,只是那个商户没有收到某个通知而已。

有个好习惯,就是把跟核心业务逻辑无关的代码,放在事务之外,防止出现问题时,影响主流程。

说实话,有时候遇到线上问题,对于我们来说未必是一件坏事。通过这次线上问题定位,让我熟悉了公司更多新功能,学习了其他同事的一些好的思想,总结了一些经验和教训,是一次难得的提升自己的好机会。


往期推荐

@Autowired报错的4种解决方案和原因分析!


SpringBoot 中的 3 种条件装配!


Mybatis中SQL注入攻击的3种方式,真是防不胜防!


本文来自互联网用户投稿,该文观点仅代表作者本人,不代表本站立场。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如若转载,请注明出处:http://www.mzph.cn/news/544692.shtml

如若内容造成侵权/违法违规/事实不符,请联系多彩编程网进行投诉反馈email:809451989@qq.com,一经查实,立即删除!

相关文章

ZooKeeper学习笔记—配置管理

为什么80%的码农都做不了架构师&#xff1f;>>> 最近在工作中&#xff0c;为了完善公司集群服务的架构&#xff0c;提高可用性&#xff0c;降低运维成本&#xff0c;因此开始学习ZooKeeper。 至于什么是ZooKeeper&#xff1f;它能做什么&#xff1f;如何安装ZooKee…

Java BigDecimal compareTo()方法与示例

BigDecimal类compareTo()方法 (BigDecimal Class compareTo() method) compareTo() method is available in java.math package. compareTo()方法在java.math包中可用。 compareTo() method is used to compare this BigDecimal object to the given object or in other words …

C# Winform 窗体美化(六、双层窗体)

六、双层窗体 大概情况 双层床体是为了平滑的创建异形窗体的一个解决方案&#xff0c;找了很多资料&#xff0c;整理了一下。 双层窗体的逻辑是建立在 UpdateLayeredWindow 不能绘制控件的基础上&#xff0c;上层再添加一个专门放置控件的层&#xff1b;这样就可以在上层“控…

批处理框架 Spring Batch 这么强,你会用吗?

来源&#xff1a;blog.csdn.net/topdeveloperr/article/details/84337956spring batch简介Spring Batch架构介绍Spring Batch核心概念介绍chunk 处理流程批处理操作指南spring batch简介 spring batch是spring提供的一个数据处理框架。企业域中的许多应用程序需要批量处理才能在…

Android Bundle类别

即使在今天发现自己Bundle类不明确&#xff0c;因此&#xff0c;花时间去研究了一下。 依据google官方文件&#xff08;http://developer.android.com/reference/android/os/Bundle.html&#xff09; Bundle类是一个key-value对&#xff0c;“A mapping from String values to …

C# Winform 窗体美化(七、Win7 Aero 毛玻璃效果)

七、Win7 Aero 毛玻璃效果 在 Win7 上有一种 Aero 效果&#xff0c;毛玻璃透明效果&#xff0c;搭配不同风格的颜色&#xff0c;效果很好。在学习 Winform 美化的时候顺便看到的这种效果&#xff0c;也整理进来了。 注意&#xff1a;Win7 上想看到这种效果需要开启并使用 Aer…

非导向传输媒体| 计算机网络

Transmission media can be categorized in two ways, 传输媒体可以通过两种方式进行分类&#xff1a; Guided Transmission Media 引导传输媒体 Unguided Transmission Media 非引导传输媒体 1)非引导传输媒体 (1) Unguided Transmission Media) It is also called wireless …

面霸篇:MQ 的 5 大关键问题详解

最近mq越来越火&#xff0c;很多公司在用&#xff0c;很多人在用&#xff0c;其重要性不言而喻。但是如果我让你回答下面的这些问题&#xff1a;我们为什么要用mq&#xff1f;引入mq会多哪些问题&#xff1f;如何解决这些问题&#xff1f;你心中是否有答案了呢&#xff1f;本文…

C# Winform 窗体美化(八、Icon)

八、Icon 之前 Winform 项目也有在 Icon 上遇到些问题&#xff08;这里的 Icon 指的是 .ico 类型的文件&#xff09;&#xff0c;比如刚开始不知道怎么让自己的程序 Icon 和其他软件一样可以放大&#xff0c;还有放大之后在音量合成器中会出现比较奇葩的效果之类的问题&#x…

Java LocalDate类| 带示例的getEra()方法

LocalDate类的getEra()方法 (LocalDate Class getEra() method) getEra() method is available in java.time package. getEra()方法在java.time包中可用。 getEra() method is used to get the era applicable for this LocalDate object. getEra()方法用于获取适用于此LocalD…

MyBatis 的执行流程,学废了!

作者&#xff1a;双子孤狼来源&#xff1a;blog.csdn.net/zwx900102/article/details/108455514MyBatis可能很多人都一直在用&#xff0c;但是MyBatis的SQL执行流程可能并不是所有人都清楚了&#xff0c;那么既然进来了&#xff0c;通读本文你将收获如下&#xff1a;1、Mapper接…

C# Winform 窗体美化(九、嵌入窗体)

九、嵌入窗体 还是关于 Winform 窗体的一些操作问题&#xff0c;这次是研究了一个嵌入窗体&#xff0c;这次学习纯属偶然&#xff0c;项目中确实没遇到过这种需求。就是把别人的程序嵌入到自己的程序中&#xff0c;就像这样&#xff1a; 这里我嵌入了测试显示器的程序 [外链图…

Mac 流程图

https://www.lucidchart.com/pages/signup?utm_expid39895073-174.qKyHpBEbQS26y86OArD-rQ.1 https://www.processon.com/

setname_Python线程类| setName()方法与示例

setnamePython Thread.setName()方法 (Python Thread.setName() Method) Thread.setName() method is an inbuilt method of the Thread class of the threading module in Python. It uses a Thread object and sets the name of the thread. Thread.setName()方法是Python中线…

SpringBoot 优雅的参数效验!

引言 不知道大家平时的业务开发过程中 controller 层的参数校验都是怎么写的&#xff1f;是否也存在下面这样的直接判断&#xff1f;public String add(UserVO userVO) {if(userVO.getAge() null){return "年龄不能为空";}if(userVO.getAge() > 120){return &quo…

NTFS Change Journal(USN Journal)详解

写在前面 最近又用了一下usn日志来获取所有文件列表&#xff0c;在分多次加载文件列表的时候发现有文件丢失的情况&#xff0c;后来发现一篇文章比较详细的讲了usn。 用cmd来读取usn日志 如图&#xff1a; 以下是转载内容&#xff1a; 还是那个文件监控的应用&#xff0c;…

Java即时类| hashCode()方法与示例

即时类hashCode()方法 (Instant Class hashCode() method) hashCode() method is available in java.time package. hashCode()方法在java.time包中可用。 hashCode() method is used to get the hash code value for this Instant. hashCode()方法用于获取此Instant的哈希码值…

系统起动时加载的过程

sof_getdjval转载于:https://blog.51cto.com/bks2015/1660178

绝,Java 中创建对象的 5 种方法!

我们日常生活中会创建很多对象&#xff0c;但是这个对象和你理解的那么对象不一样&#xff0c;因为作者不是女娲&#xff0c;不能造人。作者只是程序员&#xff0c;他只能在 Java 中创建对象。那么我问你一个问题&#xff0c;你知道 Java 中如何创建对象吗&#xff1f;这个问题…

C# Winform 窗体美化(十、自定义窗体)

十、自定义窗体 写在前面 最近在做 winform 应用程序&#xff0c;需要自定义一种窗口的样式&#xff0c;所以就随便搞了一个简单的窗口。 效果图 有两种样式&#xff0c;界面如下&#xff1a; 无标题&#xff1a; 有标题&#xff1a; 关键词 1、黑色描边边框 对于…