「技术」重复记账调查报告

周五下午的时候，测试小姐姐向我提了一个bug，简明的说就是明明记账了一次，但实际上却重复执行了两次（数据库里有两条记录）。于是围绕这个问题我调查了30个小时。。。

首先我确认了这个问题确实存在，不是误报，而且是必现的。那么先大致判断可能导致问题的服务是什么，记账服务几百年没改过了，一直很稳定，首先就排除了，我本次优化的内容，虽然有记账的逻辑改动，但是这跟bug不是一回事，这个bug走的是老的业务逻辑。那么是否可能别的同事的修改影响的呢。我先看最近的几个相关服务的发版记录，哪个分支，哪一天发的，再去直接看代码改动，希望从提交记录中直接看出问题。

看代码提交的过程中，发现了一个同事的bug，把测试数据提交到release分支了，随时可能发生产环境的。我本以为这个问题跟我的问题会有些关系，但思考了好久还是断定不是一回事。

事与愿违花了不少时间却没有发现有价值的信线索。由于我们日志打的不规范，很多关键信息也看不到，连到底请求了一次还是两次都确定不了。这个很关键，因为如果确定请求两次，那就是上游服务的问题，如果只请求一次那就是记账服务的问题。那我只能先多打了些log再发版测试。

从log中可以明确，第一重复处理的是同一台服务器，这是不同的线程池。多次测试都是这个结果，这可以说明大概率就是记账服务的问题，这就让人很纳闷了，记账服务怎么会有问题呢，最近就改了docker file文件，这肯定不会影响业务啊，而且看了生产是正常的，开发环境也是正常的，怎么就偏偏测试环境有问题呢？

记账服务的代码很简单，就是接收请求存下来再通过线程池处理，这些代码看了好几遍实在看不出有任何问题。到了周六我想来想去只有一种可能，就是spring初始化bean的方法由于未知的原因执行了两次，导致list存了了两份一样的处理对象。

为了验证这个猜想我联系运维同学让其帮忙导出一份heap信息。等我车子保养回来信心满满以为要确定问题的时候，结果发现这个判断是错误的，list内的数据很正常。这直接给我整懵逼了。

这已经是周六的深夜了，我已经没有想法了，但又不死甘心，就在傻傻的看看log。在接收log和重复处理两次的log之间还夹杂着一条log，这是哪里打印的呢？

我完全是没抱任何希望的瞎看看，结果发现这是封装的线程池执行时候打印的log，也就是说其实记账服务的线程池不是直接用java原生的，而是对其进行了一层封装再使用的，这。。。谁能想到呢。打开封装的代码一看就知道问题了，哎，为了确定我还debug了下，只要MDC对象里有值就会触发两次了，哪个傻X写的！

线上和开发因为没有在MDC存东西所以没有触发问题，而测试环境docker file的改动肯定有运维层面的依赖包导致使用了MDC，这个周一跟运维再确认下。发现的这两个问题看我看来都很严重的，因为都已经在release分支的，随时要发生产的，这要是上了生产，肯定就是大事故，年终奖就别指望了。我周一得让相关同事请我喝辛巴克才行。