记一次坏道引起OSD进程退出的问题

起因

前两天晚上手机上被Ceph集群里一个OSD进程异常关闭的告警信息轰炸，还好在OSD掉线期间，数据迁移并没有对集群的IO造成负担，大概持续10分钟就完成了。而等我登录到线上处理问题时，集群健康状态已经正常，只是在看OSD状态时，确实发现OSD-0状态已经被标记down了。

排查

检查OSD-0的日志如下

2017-08-05 22:33:10.121898 7f2586957700  0 filestore(/var/lib/ceph/osd/ceph-0)  error (5) Input/output error not handled on operation 0x7f25a2a664a8 (12956602.1.1, or op 1, counting from 0)
2017-08-05 22:33:10.121940 7f2586957700  0 filestore(/var/lib/ceph/osd/ceph-0) unexpected error code
2017-08-05 22:33:10.121941 7f2586957700  0 filestore(/var/lib/ceph/osd/ceph-0)  transaction dump:
{
    "ops": [
        {
            "op_num": 0,
            "op_name": "op_setallochint",
            "collection": "1.c8_head",
            "oid": "#1:137982ac:::rbd_data.13e92b626be232.0000000000000501:head#",
            "expected_object_size": "4194304",
            "expected_write_size": "4194304"
        },
        {
            "op_num": 1,
            "op_name": "write",
            "collection": "1.c8_head",
            "oid": "#1:137982ac:::rbd_data.13e92b626be232.0000000000000501:head#",
            "length": 4608,
            "offset": 2442240,
            "bufferlist length": 4608
        },
        {
            "op_num": 2,
            "op_name": "setattrs",
            "collection": "1.c8_head",
            "oid": "#1:137982ac:::rbd_data.13e92b626be232.0000000000000501:head#",
            "attr_lens": {
                "_": 275,
                "snapset": 31
            }
        }
    ]
}

2017-08-05 22:33:10.169852 7f2586957700 -1 os/filestore/FileStore.cc: In function 'void FileStore::_do_transaction(ObjectStore::Transaction&, uint64_t, int, ThreadPool::TPHandle*)' thread 7f2586957700 time 2017-08-05 22:33:10.167239
os/filestore/FileStore.cc: 2920: FAILED assert(0 == "unexpected error")

 ceph version 10.2.7 (50e863e0f4bc8f4b9e31156de690d765af245185)
 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x85) [0x7f2597e4aad5]
 2: (FileStore::_do_transaction(ObjectStore::Transaction&, unsigned long, int, ThreadPool::TPHandle*)+0xf15) [0x7f2597b24675]
 3: (FileStore::_do_transactions(std::vector<ObjectStore::Transaction, std::allocator<ObjectStore::Transaction> >&, unsigned long, ThreadPool::TPHandle*)+0x3b) [0x7f2597b2a39b]
 4: (FileStore::_do_op(FileStore::OpSequencer*, ThreadPool::TPHandle&)+0x2cd) [0x7f2597b2a69d]
 5: (ThreadPool::worker(ThreadPool::WorkThread*)+0xa7e) [0x7f2597e3bb1e]
 6: (ThreadPool::WorkThread::entry()+0x10) [0x7f2597e3ca00]
 7: (()+0x7dc5) [0x7f2595d6fdc5]
 8: (clone()+0x6d) [0x7f25943fa73d]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

从第一行日志可以看到OSD在硬盘这个位置0x7f25a2a664a8上的一次操作出现IO错误，进而引起数据块rbd_data.13e92b626be232.0000000000000501出现异常，然后OSD就退出了。后面的事情就是如起因一样，触发了集群将OSD-0踢出的，恢复健康。

我在服务器上简单撸了一把磁盘IO异常的位置总共发现有31处。分别如下：

root# cat ceph-osd.0.log-20170806 | grep "Input/output error"  |sed 's/^.* operation//g' |awk '{print $1}' |sort |uniq
0x7f25a2a664a8
0x7f2b718018c8
0x7f3b389418c8
0x7f3ccec178c8
0x7f3d932ef8c8
0x7f4acc8cd8c8
0x7f561b7078c8
0x7f65b552b8c8
0x7f6fdc15b8c8
0x7f7284e0b8c8
0x7f78cc54b8c8
0x7f799fbf58c8
0x7f7a7daeb8c8
0x7f81183958c8
0x7f85446838c8
0x7f88a20c38c8
0x7f8c982c38c8
0x7f8eb676d8c8
0x7f92cc5bb8c8
0x7f965f5178c8
0x7f9af7d258c8
0x7fae84a038c8
0x7fb9145ff8c8
0x7fc18c2778c8
0x7fd9d944b8c8
0x7fdf661378c8
0x7fe1587318c8
0x7feecb9c38c8
0x7fef93eef8c8
0x7ff4b69e18c8
0x7ff4eea378c8

为了验证后面新加的数据没有问题，我在硬盘挂载的目录里用dd创建100G的空文件也没有出现任何IO错误，所以基本怀疑是硬盘前面的data数据里面出现了磁盘坏道问题。摆在我面前的现在就两种情况：

• 文件系统坏道
• 硬盘坏道

第一种比较简单，用工具修复一下就好了，第二种比较麻烦，目前想到的是只能更新物理硬盘来解决。
所幸，这次我遇到的是第一种情况，下面我会将我的恢复流程简单过一下。

badblocks

badblocks是一个检查磁盘是否有坏道的工具，可以以读的方式检查，也可以以写的方式检查。默认情况下是通过只读方式去检查。

badblocks常用的参数不多，如下：

• -b <区块大小> 指定磁盘的区块大小
• -o <输出文件> 将检查的结果写入指定的输出文件
• -s 显示进度
• -v 详尽模式
• -w 写入测试，这个有可能会抹掉数据，慎用。
• -f 强制在一个已经挂载的设备上执行读写或非破坏性的写测试操作

由于我们文件系统默认的一个扇区是4k数据，所有-b 后面配置4096即可。

root# badblocks -b 4096 -s -v -o /root/badblocks1.log /dev/sdb

5396551
5432285
6077977
6135364
6144298
6144644
6145535
6147316

根据badblocks检查出来的结果，果然有8个扇区出现坏道。

那么接下的事情就是如何去修复这个8个坏道了。

恢复

最开始我打算用一些专业的坏道修复工具去执行这项任务，但是上网搜了一边都没找到合适的工具，于是决定用最简单的dd工具来修复。

备份

在做修复之前，对出现坏道的扇区进行备份

root# dd if=/dev/sdb bs=4096 skip=5396551 of=/tmp/5396551.dat count=1
dd: error reading ‘/dev/sdb’: Input/output error
0+0 records in
0+0 records out
0 bytes (0 B) copied, 0.0359454 s, 0.0 kB/s

由于我这里已经出现io错误，数据无法读取，感觉这块数据无法恢复，便没有想通过其他途径操作了。

修复

通过badblocks在坏掉的扇区里面强制测试写操作，如果没问题就将相邻扇区的数据回填到这个扇区。

root# badblocks -w -f /dev/sdb  5396551 5396551
root# dd if=/dev/sdb bs=4096 skip=5396552 of=/tmp/5396552.dat count=1
root# dd if=/tmp/5396552.dat of=/dev/sdb seek=5396551  bs=4096 count=1

将所有故障的扇区重新执行修复操作后，再用badblocks扫描时就没有出现坏道了。

Ceph恢复

Ceph恢复这块自己觉得比较粗暴，恢复成本很高，接下来我会寻找一个更好的方法来替代这次操作。
这次我的恢复过程如下：

1 . 将出现故障的OSD-0 提出集群，同时删除CRUSH

root# ceph osd out 0
root# ceph osd crush remove  osd.0
root# ceph auth del osd.0
root# ceph osd rm 0

由于这个过程会涉及到PG的迁移，会造成集群内的数据流动，好在是晚上，业务对io不敏感。等到Ceph集群恢复正常之后再将这个磁盘重新部署添加到集群内部

2 . 添加磁盘到集群

root# ceph-deploy disk zap  <node>:/dev/sdb
root# ceph-deploy osd prepare <node>:/dev/sdb

这次添加磁盘同样会造成PG分裂，引起数据同步。等到同步完成后，Ceph集群恢复正常。

思考

这次恢复的整个流程相当于Ceph集群总共要迁移两次数据，这个代价或者成本略高。而且明眼的同学发现，osd-0的磁盘里面已经存在了数据，为什么还要格式化重新产生。

对啊，我也是这么想的。根据Ceph的设计，我坏掉的数据只要找到对应的Object或者PG，手动触发让主PG的数据回填到从PG应该就能解决这个问题，而且这样成本更低。

无奈，目前自己对Ceph还不太熟悉，仍然有很多地方不会操作，而且运维起来有点不知所措。后面还是会对这块投入更多的精力来做。下次希望自己不会用这么笨的方法来处理问题呢。