住房建设部官方网站专家注册,东莞网站建设市场分析,dw做网站实例,投资网站哪个好前言公司为了保证系统的稳定性#xff0c;加了很多监控#xff0c;比如#xff1a;接口响应时间、cpu使用率、内存使用率、错误日志等等。如果系统出现异常情况#xff0c;会邮件通知相关人员#xff0c;以便于大家能在第一时间解决隐藏的系统问题。此外#xff0c;我们这… 前言公司为了保证系统的稳定性加了很多监控比如接口响应时间、cpu使用率、内存使用率、错误日志等等。如果系统出现异常情况会邮件通知相关人员以便于大家能在第一时间解决隐藏的系统问题。此外我们这边有个不成文的规定就是线上问题最好能够当日解决除非遇到那种非常棘手的问题。1.起因有个周一的早上我去公司上班查看邮件收到我们老大转发的一封邮件让我追查线上的一个NPENullPointException问题。邮件是通过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 TransmittableThreadLocalCurrentUser 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关键字竟然真的找到了一个机关。剧情出现第一次反转。有个地方写了一个rocketmq的AOP拦截器伪代码如下Aspect
Component
public class RocketMqAspect {Pointcut(execution(* onMessage(..)within(org.apache.rocketmq.spring.annotation.RocketMQMessageListener)))public void pointcut() {}...Around(valuepointcut)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_LATERrocketmq会自动将该消息放到重试队列。流程图如下这样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种方式真是防不胜防
