记一个奇怪的数据库记录重复插入的问题排查过程

背景

事情是这样滴：

有个发货服务化工程 D，依赖于数据访问服务 S 提供的若干个 dubbo 接口，还有一个服务接口自动化测试工程 T ， 可以直接调用 D 和 S 的 dubbo / httpRestful 接口来自动化回归测试这两个工程暴漏的服务接口。当改动 S 或 D 的代码后，运行 T 里的可重复执行的发货自动测试用例，若全部通过，则可验证 S 或 D 改动是有效的。

发货的核心逻辑是： 在前置条件校验通过后，D 需要调用 S 的 insertExpress dubbo 接口来插入发货的数据记录。一个单商品无退款订单，应该分别只插入一条 oe（简称 X）, oe_detail （简称 Y）记录。

问题

当同步升级 D , S 依赖的 common-model 包的版本后（差别仅在于 BaseResult 的 code 类型由字符串变成整型），之前一直执行成功的发货自动测试用例现在失败了。

开始以为是多个订单号的发货测试用例之间存在隐性的依赖，导致连续运行的时候失败了；于是，我注释掉其他的订单号，只针对一个最普通的订单号运行单次发货用例；然而，即使是单次调用针对最普通订单的发货服务的 Restful 接口，也会失败。

使用Debug模式单步调试了下，发现是一个 assert 语句未通过；而这个语句未通过的原因，是针对这个单商品订单号插入了几乎完全相同（除ID值不同）的数据库记录 X(id1) ，X(id2), Y(xid=id1), Y(xid=id2)。

运行 insertExpress 的数据库DAO单元测试是没有问题的，说明DAO的数据插入方法应该是没有问题的；也不存在并发访问数据库的情况。

由于QA环境有问题，我就部署到预发环境，看看是否有问题，能不能找到线索；结果预发没有问题；推测QA环境可能哪里有问题，但是又想不出是什么。

排查

迷惑因素-jar包升级

由于此问题碰巧是在 common-model JAR包升级 1.0.1之后出现的，一度以为是这个升级导致。对比实验也似乎非常确凿地支持这一点。当我把工程 D 切回到升级前的分支后，用例就执行成功了，切到升级后的分支，用例又失败了。可是，这个升级中工程 D 只改了一行跟发货毫无干系的代码，就是把 String 类型的 errorCode 解析成 int 类型返回给调用方而已，几乎不可能是导致用例失败的原因。不管怎么说，这个Jar包的升级是必须的，必须在升级的基础上进行排查。

运行多次-概率性出现

不信邪的我多次执行这个单次调用服务接口的测试，时而换个订单号执行下，发现有的时候成功，有的时候失败。这下可奇怪了，同样的代码，为什么有时成功，有时失败呢？接连运行的测试之间有依赖？ 不大可能啊！

于是我编写了一个通用方法，可以多次执行同一个测试，并统计失败次数。发现这个测试确实是概率性成功，且成功的概率还是很小的。失败都是因为单次调用却插入了两条完全相同的数据库记录。这究竟是怎么回事呢？ 难道是事务代码编写有问题，导致实际调用了两次SQL？

聚焦核心接口

由于 D 调用 S 的 insertExpress 方法是实现发货的核心逻辑（除了这个就是各种校验了），因此可以聚焦 S 的这个方法。既然多次调用D的发货服务接口概率性失败，那么多次调用 S 的 insertExpress 会怎样呢？在 T 中多次执行 S 的 insertExpress 的测试用例，几乎都是成功的。很难相信这个结果：只有这个方法会插入数据库记录，如果调用 D 的发货测试用例多次失败，那么几乎可以肯定是 S insertExpress 多次失败了。然而 调用 D 的发货测试用例的失败概率 与 调用 S 的 insertExpress 的失败概率是成反比的。

代码细审

从代码入手吧，仔细读读代码，看看是否有因为马虎写错的地方，或者在某个细微的地方犯了错误。果然，发现事务代码似乎有点问题：

会不会因为 transactionStatus 取不同的值多次执行了后面的插入呢？会不会因为 T 调用 D 的接口超时重试，导致这个方法被多次执行了呢？ defaultTxTemplate ？ 这个不是引用非分库的数据源吗？ 可是 X, Y 记录是在分库的数据源里啊，为什么引用非分库数据源的事务管理器可以访问分库的数据源的数据呢？ 如果不可以，为什么发布到预发和线上都没有问题呢？如果可以，又是什么缘故呢？此外，还发现了一个问题：工程 D 的 OrderExpressService 的 Bean 名称在 Spring配置文件里写成了 orderExpressDetailService , 但代码里引用的却是

@Resource private OrderExpressService orderExpressService

这代码是怎么跑起来的？真是一波未平，一波又起。

打印日志-排除可能

于是，我在 S 的事务代码中加了日志，部署到QA环境再执行。

令人惊讶的是，日志清清楚楚地显示，事务代码只执行了一次，SQL执行中也显示只插入了一条记录，但是查询 order_express_detail 的时候，却查到了两条！ 实在令人百思不得其解！

ngrep抓包-疑窦丛生

早会上说了这事，工作伙伴奎哥建议使用 ngrep 抓包试试。其实一直对抓包这个词感到神秘，这会正好学学怎么玩。在部署了 S 和 D 的 centos 机器上使用 sudo yum install ngrep 安装 ngrep 后，就开始抓包行动了：

(1) 在 D 上使用 sudo ngrep -W byline -d eth0 port 8025 打印本机到 D 的网络调用请求及数据；

(2) 在 S 上使用 sudo ngrep -W byline -d eth0 port 20881 打印 D 到 S 的dubbo服务请求及数据；

(3) 在 S 上使用 sudo ngrep -W byline -d eth0 port 3007 打印 S 到 mysql 的请求及数据。

然而，请求和插入SQL依然只执行了一次，但是查询的时候却有两条。这条额外的插入语句究竟是怎么来的呢？我还对比了下成功和失败情况下抓包数据有什么差异；开始捕获了一点似乎有用的线索，比如SQL的设置等，但后来发现成功的时候也会有这些设置。

一语惊醒梦中人

中午吃饭的时候又跟奎哥说了下这些奇怪的事情，奎哥说可以让数据库同学抓包看看，插入SQL的来源IP是什么。这句话点醒了我： 不同的IP？不同的机器同时插入数据库？ 突然我记起前不久QA在搭建集成环境，当时测试同学还找我协助解决搭建 D, S 的问题。会不会两个机器都接到了dubbo服务请求去插入了数据库呢？想到这里，我马上登陆到那台QA集成环境的机器上，使用 sudo ngrep -W byline -d eth0 port 3007 进行抓包。真相大白了！ 果然这台机器也执行了dubbo服务请求，插入了数据库记录！

可是疑惑还未完全消散： 为什么发送一个请求到注册中心，多个提供服务的应用都会执行呢？按照负载均衡原理，这些服务器不是只有一台才会去执行请求吗？线上不是也部署了多台提供相同服务的应用服务器么？它们也会同时插入数据库记录吗？后来问了下中间件同学，确定是 QA 集成环境和 QA测试环境都注册到同一个 etcd 环境，导致同一个dubbo 请求被分别执行了一次。

多工程联调

那么，那个引用错误的数据源的事务管理器又能插入到正确的分库数据库是什么缘故呢？ 找RDS同学帮忙看了下，没发现数据库这边的线索；于是在本地启动 D , S 工程， 临时修改 S 的 dubbo 端口配置为 20886 避免与 D 的冲突，并修改 D 的配置直连 S 的接口进行调试。感谢奎哥的工作！通过单步调试发现， DAO 配置的是分库的数据源；尽管从事务管理进入时引用的是非分库的数据源，但是到达DAO Session 层执行SQL 的时候就转变成分库的数据源，从而能够正确执行SQL了。就好比函数里的局部同名变量覆盖了全局同名变量。不过这里到底是有问题的，后面需要修复。

另外，Spring bean 声明的名称与代码里引用的不一致，却能正常工作，是因为 @Resource 在找不到与名称一致的 bean 时会自动创建类型相同的 bean ; 这些都是细小的问题，但隐藏着风险。

AllPassed

明白了原因所在，解决就好办了。我征求了QA 同学的意见，将QA集成环境的那台机器的 S 应用停掉了，测试用例立即就全部通过了。

小结

排查疑难问题总是让人绞尽脑汁百思不得其解，可是解开谜底的过程，又是个痛并充实着的过程，也会很好滴提高解决问题的综合能力。就拿这次问题排查来说，综合使用了“排除迷惑因素、对比实验、多次执行、聚焦核心代码、代码细审、日志打印、单步调试、多工程联调、网络抓包、数据对比、环境部署、与工作伙伴交流探讨”等技能。

当出现问题时，或许我们应该更善于从整体上找原因和解决方案。针对这个问题，如果从单个应用的角度去考虑，就会考察代码写得是不是有问题（当然确实有点问题，但不是真正原因）；如果从环境去考虑，就会思考是不是有多台机器同时插入了数据库。比如手机充不上电是因为电源芯片烧坏了，解决方案是换个电源芯片。但实际上由于使用了两年，可能电池或其它部件也老化了，从整体来说换个手机更划算。再比如ide报第75行语法错误，很可能是第73行少了个分号引起的连锁出错反应。

单步调试依然是调试细微问题的最简单的武器。任何问题都逃不过单步调试的眼睛。排查“引用错误的数据源的事务管理器能插入到正确的分库数据库”这个问题，正是使用单步调试，发现数据源又被偷偷换回来了。

排查问题的手段也要灵活多样。既要纵向深入，也要学会横向对比，多角度探查。

与工作伙伴交流也是非常重要的。如果不是奎哥的两次重要提醒，估计还要花更多时间在云里雾里不得其解。

在解决问题的过程中，顺便还发现了两个隐蔽的小问题，在大规模线上服务分流之前，简直是天意！