那些年我们犯过的错（一）——豆瓣Xupeng：补齐那丢失的三分钟数据

2013年6月底，下厨房由于技术人员操作失误，导致近两个月数据丢失。下厨房的技术博客对整个事件进行了总结，记录了整个事故的隐患、发生、数据修复、以及如何避免此类错误再次发生的一些措施。

\\

大部分有经验的运维、DBA都少不了做过误删数据的事情，这次事件引起了很多工程师的共鸣与讨论。就在该事件发生后的第二天，豆瓣的Xupeng撰写了一篇博客，记录自己《这几年犯的错》。他表示：

\\

这几年犯过很多次严重影响线上服务的错误，像重启了错误的节点这样的事情应该算作能够对线上造成影响的最微不足道的错误。

\\

在文中，Xupeng简单罗列了这些年犯过的一些错误，包括停用线上 memcache 集群、软件 bug 导致线上 memcache 集群被污染、恢复数据时删除了更多数据等。

\\

犯错误的经验其实是跟源代码一样宝贵的信息。一个有经验的工程师不仅要了解项目是如何实现的，更重要的是要了解实现的过程中可能会遇到哪些坑，以及如何绕过它们。那么，为什么不把犯错误的经验也像源代码一样，将错误是什么、如何发现的、如何解决的、之后如何预防等步骤，详细的记录、共享下来呢？

\\

从今天开始，InfoQ将开辟《那些年我们犯过的错》话题，隶属“故障排除”专题下，专门邀请经验丰富的工程师们分享他们处理故障的经验。

\\

第一位受邀分享的嘉宾，正是上面介绍的Xupeng同学。

\\

嘉宾简介：Xupeng，真名员旭鹏，Linux 爱好者，Python 程序员，Mac 用户，豆瓣首位全职 Linux SA，关注 Linux 性能优化、虚拟化，擅长 Linux 及其上软件系统的 troubleshooting，同时管理豆瓣若干 MySQL 集群。

\\

本文分享的是Xupeng在博客中提到的最后一个事件，即“误操作并误删数据文件”事件。

\\

发生了什么事？

\\

有一个这样结构的 MySQL 集群：

\\

    -----           -----\    | A |    \u0026lt;-\u0026gt;    | B |\    -----           -----\    /    \\\ -----  -----\ | C |  | D |\ -----  -----\

\\

A 是 master 节点，接受线上的读写请求，B 和 A 同构是 A 的热备，A 和 B 互相同步，当 A 有故障时可以把 B 提升为 master 接受读写请求，C 和 D 是 A 的 slave，用于离线查询和备份等目的，这是一个比较常见的 MySQL 架构。

\\

有一次对一张比较大的 MySQL 表做 schema 变更，先在 slave (B) 上做完变更之后做了主从切换，使线上使用新的 schema，但切换之后我发现新的 slave (切换之前的 master: A）的数据不对，后来在仓促的修复过程中又误删了数据文件，现在想起来还一身冷汗。

\\

如何发现错误？

\\

在主从切换之后，我像以前一样在新的 slave (A) 上执行 show slave status，检查新的 slave 节点同步是否正常，Slave_IO_Running 和 Slave_SQL_Running 都是 Yes，Seconds_Behind_Master 为 0，这表明 slave 的 IO thread 和 SQL thread 在正常工作，但 Exec_Master_Log_Pos 却一直保持不变，show master status 的输出也表明 slave 上没有新的 binlog 写入，这一定是哪里出了问题，线上不可能没有新的数据写入。

\\

立刻到 master (B) 上确认了的确是有写操作的，但是 B 上却没有 binlog 记录，随即发现了 B 上的 binlog 是被停止了的：

\\

mysql\u0026gt; show global variables like 'sql_log_bin';\\+---------------+-------+   \| Variable_name | Value |   \+---------------+-------+   \| sql_log_bin   | OFF   |   \+---------------+-------+   \

\\

这是我之前在 B 上做 schema 变更时，为了避免执行时间很长的 DDL 被同步到 A 上阻塞线上应用，本意是停止当前 session 的 binlog 记录，应该执行的是 set sql_log_bin=0，但实际上却执行了 set global sql_log_bin=0 停止了整个 server 的 binlog 记录，于是主从切换之后，新的 master 就不再记录 binlog。

\\

当时所采取的措施？

\\

从完成切换到我意识到问题和可能的原因，已经过去了三分钟，这意味着 A, C 和 D 节点与 B 相比，缺少了最近三分钟的数据，并且只有 B 这一个节点才有完整的数据，于是第一时间恢复了 B 节点的 binlog 写入和 A 节点的同步。

\\

紧接着就开始考虑该如何在 A，C 和 D 上补齐缺少了的那三分钟数据变更（有新写入的数据，被修改的数据和被删除的数据）。

\\

我们在数据库节点上使用 tcpdump 抓取并记录 MySQL 的所有通信，这样做的目的主要有三个：

\\

1. 当事后发现 MySQL 有异常比如突发的性能问题时，可以分析之前抓取的数据来定位问题\
2. 安全审计\
3. 在有计划地切换主从之前，使用从 master 上抓取的查询对 slave 进行热身\

因此首先想到的就是使用 tcpdump 记录的 MySQL 通信数据来恢复，但是很快就发现了问题：由于 A 节点是在一个错误的数据集基础上重新开始同步的，接下来的几分钟内同步就出错了，原因是在那缺失的三分钟变更内有新记录写入但没有记录 binlog，恢复 binlog 写入之后，记录又被删除，删除操作被同步到 A 上，但由于 A 上之前并没有写入过这条数据，删除操作就失败了，我这才意识到第一时间恢复 A 的同步是错误的，正确的做法应该是第一时间恢复 B 的 binlog，但暂停 A 的同步。

\\

如果没有率先恢复 A 的同步，那么就可以先尝试在 A 节点上回放 tcpdump 记录下的 query，但由于 A 已经在错误的基础上进行了几分钟数据同步，这条路基本上是走不通了，并且即便没有立刻恢复 A 的同步，也几乎没有希望仅仅依靠 tcpdump 抓取的数据进行准确的恢复，原因是 tcpdump 抓取到查询顺序和 master 上执行的顺序并不一致，在数据恢复这件事上，tcpdump 和 binlog 不等价。

\\

紧接着考虑使用 Percona 的工具 pt-table-sync 来同步 A 和 B，但考虑到同步几百张表的过程会非常漫长，在这个过程中还会持续地给线上带来压力，也放弃了在紧急状况下使用这个方案。

\\

能想到的最安全的方式只剩下了一个：使用 Percona Xtrabackup 对 B 进行热备份，重建新的 slave。

\\

经验总结

\\

这次事故的教训是，应该尽量使用软件而不是手工来执行确定性强的重复性操作。在执行重复性操作上，软件远比人靠谱，即便是人对着 checklist 一步一步执行，犯错误的几率也比软件大得多。应当使用经过验证的工具比如 Percona 的 pt-online-schema-change 进行 schema 变更，避免手工操作，数据库切换前后的检查也应该使用工具而不是手工，故障恢复之后第一时间改进工具以免这样的事情再次发生，对于 SA 和 DBA 来说，工具开发和改进是一件需要持续投入精力去做好的事。

\\

---

《那些年我们犯过的错》话题正在征稿！投稿方式：

\\

1. 回答以下问题：\\
   1. 介绍一下你印象深刻的、你犯过的一个错误。\
   2. 你是如何发现/捕捉到这个错误的？\
   3. 发生了错误之后，你尝试做了哪些事情？\
   4. 你是如何从错误的症状跟踪到错误诞生的原因的？\
   5. 之后，你做了哪些工作防止此类错误再次发生？\
   \
2. 撰写一段你的个人介绍。\
3. 发信给 editors@cn.infoq.com ，邮件标题注明《那些年我们犯过的错》投稿，将上述内容粘贴入邮件正文当中。\

期待您的来信！