teuthology数据不一致问题分析过程

注意：这个bug非官方引入，因此对使用官方代码的ceph环境没有影响

问题场景

teuthology某个测试用例执行失败，错误原因是数据不一致：

并且之前没有跑出来过。没跑出来的原因可能是这个用例没执行到，或者执行到不是必现的。

解决bug第一步：复现bug

要解决bug，第一步必定是找到必现场景，或者高概率复现场景，只有稳定复现的bug，才有希望找到bug原因并修复，否则只能靠推测或者猜测，永远没有办法确认bug是否真正的解决了（加不加修复代码都跑不出来，就不能说问题已经修复了）。

因此这里分两个方向：
1. 分析teuthology测试过程中的ceph日志
2. 直接反复执行失败的用例，看是否可以复现

这两个方向可以并行做，先在已经搭好teuthology环境下写脚本反复执行跑失败的用例，差不多10分钟可以跑完，反复执行看复现概率。

测试执行过程中继续分析之前跑失败的teuthology用例的ceph日志，ceph.log除了上述scrub不一致的错误之外没有别的异常日志，ceph-mon.log里面有所有测试期间收到的客户端操作命令请求，比如osd的up、down、out、reweight、进程退出启动等，然后就是配合rados bench进行io写入，执行完毕功能用例后，进行pg deep-scrub操作，检查是否有数据不一致情况，ceph相关配置项都是在提前配置好的，也有个别是在用例里覆盖掉的。

在看osd日志，除了正常的IO写入外，就是异常的恢复IO，分析srcub发现的不一致对象，找到其所有的IO路径，刚开始没什么头绪，写入过程中涉及到peering、remap等过程，发生过多次Retry，切换过2个主osd，有点被误导，看了一天也只是了解到bug相关场景的基础（或者说用例执行的逻辑），对问题的分析每一实质进展。

分析日志过程中teuthology单独跑测试发现可以复现，并且概率较高（10次必现）。之后继续分析二次复现出来的ceph日志，并尝试更换之前的版本跑相同的用例。

二次复现的日志相对于第一次跑出来的场景要简单许多，不一致的对象是正常写入的，只是osd在恢复对象过程中被打断（osd进程被强制干掉，并且osd是从），然后再次启动后并没有继续恢复流程，最后在scrub过程中发现对象大小不一致，用例执行失败。

尝试老版本复现仍然有问题，也就是说可以排除是本次修改引入的bug，继续使用更老的版本（线上版本）进行复现，仍然可以复现，并且复现概率类似，说明是更早的问题。

根据第二次复现的场景，尝试在本地开发环境使用故障注入的方式进行bug复现，由于是在从osd接收到对象恢复的op后进程被杀掉导致的bug，因此在对应的函数里增加assert(false)操作即可：

添加上述代码后，在osd正在恢复对象的过程中，动态修改配置项osd_recover_inject_assert=true，osd会assert退出，之后再启动这个osd，尝试后发现这个方式可以几乎100%复现这个bug，问题基本就有很大解决的希望了。

首先分析代码流程，发现是osd再次启动后，恢复到一半的对象没有再次加入到missing列表，导致主osd不会再次将其恢复。
但是没有找到根本原因，为啥没有加入missing列表中？因为osd启动时，load_pgs过程中发现这个对象存储（可以读到），并且版本与pg log中的一致，但是为啥对象在？并且版本一致？发现是在分段恢复时，第一段（比如4M中的第1M）恢复的时候就会把对象版本写入对象attrs属性中，之后恢复剩余的部分数据时不会进行修改。

问题的关键就是osd再次启动后对象为啥是存在的？当时怎么也没想明白。

尝试L版本复现

于是尝试分析L版本代码进行对比，发现相关流程并没有改动（load_pgs和分段恢复时第一段设置对象attrs），但用同样的故障注入方式不能复现这个bug，原因是pg的missing对象列表已经跟pglog一起持久化到磁盘上（rocksdb？），只有在对象完全恢复之后才会被删除掉（这部分代码没分析，但猜测肯定是这样），如果按照上面的复现方式进行操作，osd assert退出再启动，pg的missing对象列表在load_pgs时会从rocksdb里加载进来，然后就可以继续恢复。

尝试官方版本复现

分析到这里以为是0.94.6版本本身就有的bug，但问题第一次出现时就google过了，没有搜到任何类似的bug报告，并且tracker.ceph.com上也没有类似bug报告，而且以我们的teuthology复现概率来看，这个bug基本算是必现的，如果官方版本存在，那肯定有人报告。所以就在开发环境通过上面的故障注入方式，搭配官方的0.94.6版本代码进行复现，发现果然是没有问题的，分析到这里基本就可以确认是我们自己修改的代码导致的bug，对比下线上版本和官方0.94.6版本，看到基本唯一的改动就是部分恢复功能，基本可以确认这个功能引入的（其实问题一出现我们就怀疑这部分代码，当时应该第一时间确认，就可以少走很多弯路，但也就意味着少学习很多东西）。

分析部分恢复优化代码

分析部分恢复优化代码，可以看到在submit_push_data函数里有修改数据恢复的pg目录（head还是TMP）：

解决方案

因此就加入日志进行复现，发现确实是如此，确认问题之后就是找解决方案了，组长建议把分段恢复功能关闭（注意是官方的分段恢复，而不是我们修改的部分恢复，部分恢复是指分段里面的一部分，比如1M分段中的128K数据，这个功能可以减少实际需要恢复的数据量），也即把osd_recovery_max_chunk配置项设置为默认值（8388608），当前我们线上和teuthology测试用的都是131072。这样的话，

尝试修改配置项之后用故障注入方式及teuthology单独执行相关bug用例，不一致问题均不再出现，问题确认修复。

可以看出，问题分析过程虽然比较曲折，但问题的原因分析清楚之后，却非常简单，改动方案也很简单。一般来说改动方案越简单，才说明找到了真正的问题点。