记一次并发场景下的问题排查

记一次并发场景下的问题排查


上周周四,项目上线,我负责的部分主要是账单重构,说来也巧,本来是没有这个需求的,由于当时划分给我的项目其实已经被别的线接走了,后来经过讨论,这次的业务需要其他线支持,一下任务少了一大截,比较轻松,看了看下单流程,代码不符合我的审美就给重构了(现在想想真是自信过头,没经过架构评审,模型纯自己写的,就给重构了。。果不其然。。)。废话不说,直接进入正题。

问题出现

四点钟上线完成,盯着日志,发现一单下单异常,仔细看了一下发现入参少了一个参数,问题很神奇,没有这个参数的情况下按理来说就不应该走到相应的流程去,但是却走进去了,这时候还没当回事,毕竟上线过程中,机器重启啥问题都可能出现,不大规模爆发就好(其实这个时候已经隐隐感觉不太对,但是我对自己的代码相当自信,也没有特别上心)。

大规模爆发

六点多钟就是吃饭高峰期,这个期间流量暴增,请求会达到一个峰值,这个时候刚上过线,肯定是要紧盯一下的。五点多出现3-4单下单异常,问题一样,都是不应该走到那个逻辑中,但是却走了进去。。这里为了给读者一个比较清晰的认知,贴出部分代码:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
//这里的c就是channel的实例
if (condition) {
if () {
if () {
c.addNode(n1);
} else {
c.addNode(n2);
}
} else {
c.addNode(n3);
}
} else {
if () {
c.addNode(n4);
} else {
c.addNode(n5);
}
}

模型不复杂,用的是管道-节点的模型,问题就是condition判断为true的情况下,channel中添加了n4或者n5节点!

担心用户大面积下单失败,赶紧让测试的同事在线上环境中测试了一下,发现一切正常。这时候开始意识到,妈的大事不好!根据经验来看:

  1. 非必现的问题比必现的问题更难排查。
  2. 没有出现任何异常,这种情况下更是难下手。

六点多,问题爆发,一分钟几十单失败,问题都是同一个。。由于公司流量还是比较大,尤其高峰期,比例不算大,可能几十单上百单中会有一单下单失败,但是在后台来看,高峰期有将近400单下单失败!大事不好!

一个同事捕捉了一下某个用户的行为,这个用户第一次下单失败之后又进行了一系列加菜操作之后第二次下单,下单成功。。由于用户感知不大,所以线上反而没有人反馈有问题,这也是比较庆幸的一点。

赶紧把大家叫过来一起捋了一下逻辑,反复看了几遍,发现没啥问题,这时候怀疑是并发情况下才会出现,先定位问题,添加了一些日志记录,等十点多发一次,再看看第二天的效果,是否能直观的给出一个错误的原因。这个时候已经七点多钟,由于负责的是P1级应用,马上发已经不太现实,只能等晚上十点以后了。

这期间反复看了几遍逻辑,由于是重构的代码,别人已经基本帮不上忙,只能自己找(自己设计的模型出了问题,跪着也要找出来T T)。本来打算在公司过夜了(我们学校晚上十点半宿舍就关门了。。我回学校要将近两个小时),后来讨论了一下,由于不是必现问题,晚上流量又比较少,估计也出现不了,先上掉,第二天再看。

回滚

我以为打个补丁,没啥大问题,就先走了。九点多,还在公交车上,关注了一下线上反馈的群,有商家开始反应,金额对不上,有付款消息,收银机却收不到,赶紧在项目的群里说了一下情况,交易中心的架构师回复说如果下单流程走串(比如正常流程下单却调用了外卖下单接口),由于支付消息是根据流程来划分的,所以是存在收不到消息的情况,这已经不是小问题了,程序员都知道,只要跟钱打交道的流程都是重中之重的流程,这是不能出错的,赶紧给释迦打电话,看情况赶紧回滚。。

这个项目涉及到的工程多达十几个,大面积回滚不太可能了,考虑把我负责重构的代码部分回滚掉,赶紧把老代码拉出来,晚上十点多发布了。。

这时候反复捋了几遍逻辑,都觉得应该没什么问题,各种情况也都考虑了。。

问题还原

第二天来了赶紧把代码找出来,先简单的测了一下模型,没出现问题,这时候开始怀疑是不是我调用的节点没错,交易中心内部调用出了问题,询问之后被否认。。没办法了,只能把线上出问题的代码拿出来,再测。

第一次测试把线上出现错误的数据拿出来当入参,启动五百个线程同时跑,没有出现问题,同事提出了一个建议:多个场景下并发跑,这样看看效果。第二次测试两个场景,各启动200个线程跑,同样没出问题,这时开始觉得应该问题不在我这。。

下午想了一下,更严密的测一下,四个场景,每个场景几十个线程,交叉跑 — 问题出现!

排查

跟预测的一样,管道中的节点走串了,在条件condition为true的情况下,居然走到了只有condition为false才可能走到的节点中。。

这时候基本确定是并发问题,为了更加确认,直接在方法上加最大粒度的锁,问题解决,这时候已经确定就是并发引起的偶现问题,头大。。

这种问题基本上可以确定是变量共享导致的问题,那么首先怀疑到就是管道出问题,管道被多个线程共享了,添加节点的时候出现了问题,由于我设计这个模型的时候已经考虑到了这种情况,管道都是跟线程绑定的(ThreadLocal),但是现在出了问题就要解决,测一下,发现在多线程的情况下,管道和线程的绑定关系很稳固,没有出现同一个管道出现在了不同线程中的情况,继续头大,管道没问题,那么每个独立的管道中添加节点就不会有问题才对。

甚至都怀疑到dubbo上去了。。。周五下午四点多,这时候几百个线程的情况下,问题已经必现,但是调试也好,条件断点也好,任何情况下代码层面都没出现会串的情况。。。这种是最变态的问题,代码都没问题,只能从逻辑层面考虑,几乎没法动手解决,只能通过经验、逻辑、角度等方面去考虑问题了。。

跟同事讨论了一下,讨论中突然想到,也许管道-节点模型中存在能共享的变量?之前我对自己设计的模型自信心还是很强的,再加上那么多测试,基本不会出什么问题,所以一直没怀疑到模型上去,但是现在的情况是无所不用其极,没办法了。

赶紧看了一下,找到问题!

解决

由于使用的模型存在节点的概念,节点的后继节点的添加是被绑定到前继节点的next属性中,但是管道是线程安全的,按理来说不同线程的不同节点都是相互独立的,不应该出问题才对,那么问题出在哪?就出在节点并不是相互独立的而是共享的!

由于每个节点是托管给spring容器的,而spring容器的bean默认都是单例的!那么不同线程就可以使用相同的节点,这时候如果channel1在跑逻辑,channel2在添加节点。。那么假设channel1中的节点顺序是:

1
n1 -> n2 -> n3

假设channel2中的节点顺序是:

1
n1 -> n2 -> n4

由于单例,那么n2在内存中指向了同一个对象,channel1在跑完n2的时候,正好channel2把n2的后继节点改成了n4,这时候,就可能出现节点跑串的情况!

那么解决很简单了,直接把节点注入成prototype就可以了。

总结

这个问题从出现到解决,历时一天多,中间比较焦头烂额。经此一役,以后重构代码必须慎之又慎,模型设计必须经过大神的评审,尤其是下单这么重要的流程,一定要小心小心再小心。

其实这个问题不单是经验不足,也有模型设计上的问题,这个也跟排骨讨论过:节点和节点的关系,应该依托于管道管理,节点和节点之间不应该有任何绑定。所以后面考虑把之前的模型改一下,如果是管道在逻辑判断之前就已经把节点添加好了,只需要根据不同的业务来取不同的管道,这个问题就不会出现了,不过:福兮祸所依,祸兮福所伏,多出问题对自己的成长肯定是有好处的。

即将毕业,遥想当年一个空指针问题都能让我不知所措,如今已经在排查解决并发问题了,感慨良多,期待未来更好的自己!