大规模删除bucket使OSD失联引发持续pg异常处理

2018-09-01

字数统计: 2.2k字 | 阅读时长≈ 10分

最近集群发生了一个奇怪的现象，微信端不断收到集群pg异常和osd down的告警，几经排查，最后找到了解决方案

写在前面

松鼠哥的ceph专业课程上线啦！
面向新手同学，从0实战，全面入门ceph安装部署与运维，有需要的同学赶紧联系松鼠哥订购吧：

最近集群发生了一个奇怪的现象，微信端不断收到集群pg异常和osd down的告警，几经排查，最后找到了解决方案

问题的发生

因为第一套集群写满后，不再进行写入，而已经保存了的数据超过一定时间后就需要删掉，以便腾出空间放更新的数据，在使用多节点、多进程同时进行24个bucket删除的情况下，删除一段时间后，微信不断收到告警，显示集群的pg一直处于不健康状态，伴有osd 反复up/down的警报，经过初步排查，发现有一个ssd-osd联系不上其他ssd-osd

2018-08-27 11:07:42.031157 7fc645fa1700  1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7fc627fac700' had timed out after 60
2018-08-27 11:07:42.031595 7fc6467a2700  1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7fc627fac700' had timed out after 60
2018-08-27 11:07:42.200264 7fc64482c700  1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7fc627fac700' had timed out after 60
2018-08-27 11:07:43.065003 7fc6467a2700  1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7fc627fac700' had timed out after 60
2018-08-27 11:07:43.065065 7fc6457a0700  1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7fc627fac700' had timed out after 60
2018-08-27 11:07:43.334032 7fc645fa1700  1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7fc627fac700' had timed out after 60
2018-08-27 11:07:43.334128 7fc6457a0700  1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7fc627fac700' had timed out after 60
2018-08-27 11:07:43.565706 7fc6467a2700  1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7fc627fac700' had timed out after 60
2018-08-27 11:07:43.566399 7fc6457a0700  1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7fc627fac700' had timed out after 60
2018-08-27 11:07:43.635407 7fc6457a0700  1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7fc627fac700' had timed out after 60

osd健康检查显示心跳检测异常，对端osd显示也一直连不上这个osd

Aug 27 11:07:01 gz-ceph-52-203 ceph-osd: 2018-08-27 11:07:01.337899 7f73a5b4d700 -1 osd.173 8171 heartbeat_check: no reply from 172.25.52.203:6841 osd.172 since back 2018-08-27 11:06:20.794024 front 2018-08-27 11:06:20.794024 (cutoff 2018-08-27 11:06:41.337893)
Aug 27 11:07:02 gz-ceph-52-203 ceph-osd: 2018-08-27 11:07:02.338030 7f73a5b4d700 -1 osd.173 8171 heartbeat_check: no reply from 172.25.52.203:6841 osd.172 since back 2018-08-27 11:06:20.794024 front 2018-08-27 11:06:20.794024 (cutoff 2018-08-27 11:06:42.338025)
Aug 27 11:07:03 gz-ceph-52-203 ceph-osd: 2018-08-27 11:07:03.338137 7f73a5b4d700 -1 osd.173 8171 heartbeat_check: no reply from 172.25.52.203:6841 osd.172 since back 2018-08-27 11:06:20.794024 front 2018-08-27 11:06:20.794024 (cutoff 2018-08-27 11:06:43.338132)
Aug 27 11:07:04 gz-ceph-52-203 ceph-osd: 2018-08-27 11:07:04.338545 7f73a5b4d700 -1 osd.173 8171 heartbeat_check: no reply from 172.25.52.203:6841 osd.172 since back 2018-08-27 11:06:20.794024 front 2018-08-27 11:06:20.794024 (cutoff 2018-08-27 11:06:44.338542)
Aug 27 11:07:05 gz-ceph-52-203 ceph-osd: 2018-08-27 11:07:05.338659 7f73a5b4d700 -1 osd.173 8171 heartbeat_check: no reply from 172.25.52.203:6841 osd.172 since back 2018-08-27 11:06:20.794024 front 2018-08-27 11:06:20.794024 (cutoff 2018-08-27 11:06:45.338654)

第一时间怀疑是tcp的问题，是连接数不够吗？不是，配置的tcp连接数等系统参数都是很大的，不会出现不够的情况；是网络不通吗？不可能，因为只有一个osd有问题，一个节点多达46个osd，偏偏一个osd出问题，不像是网络问题；于是使用strace跟踪ssd-osd的进程，看看它在干什么

9.01%  libc-2.17.so          [.] __memcpy_ssse3_back
6.23%  libc-2.17.so          [.] __memcmp_sse4_1
4.31%  ceph-osd              [.] rocksdb::MergingIterator::Next
3.70%  ceph-osd              [.] rocksdb::InternalKeyComparator::Compare
2.79%  libtcmalloc.so.4.4.5  [.] tc_deletearray_nothrow
2.62%  ceph-osd              [.] rocksdb::BlockIter::ParseNextKey
2.13%  ceph-osd              [.] 0x0000000000de4d0e
2.12%  ceph-osd              [.] 0x0000000000de4d19
1.86%  ceph-osd              [.] rocksdb::DBIter::FindNextUserEntryInternalq
1.64%  [kernel]              [k] do_blockdev_direct_IO
1.54%  [kernel]              [k] _raw_spin_lock_irqsave
1.51%  ceph-osd              [.] rocksdb::LRUHandleTable::FindPointer
1.47%  [kernel]              [k] _raw_spin_lock_irq
1.20%  [kernel]              [k] megasas_build_and_issue_cmd_fusion

看起来，这个osd进程主要是rocksdb在忙，可是集群此时已经没有在进行删除或者写了，为什么rocksdb还会这么忙呢？

为了进一步得到更详细信息，使用iotop得到实际io操作的线程号后，再次使用strace查看io到底在干什么

pread64(24, "-\"\00090820.5971254745506465.jpg\0\275B"..., 8192, 300595830784) = 8192
pread64(24, "\0\0\0\300\265D[f\373\260\r \0\0\0006770ae345b0ab1728"..., 8192, 15108136960) = 8192
pread64(24, "e7e1ef1acc5cdf4a63050\4\0\0\0tupu\16\0\0"..., 8192, 15108141056) = 8192
pread64(24, "\0\0\0tupu\16\0\0\0tupu-s3-system\30\0\0\0app"..., 8192, 15108145152) = 8192
pread64(24, "\0\0application/octet-stream\224\265\1\0\0\0"..., 8192, 15108149248) = 8192
pread64(24, "tion/octet-stream\274K\1\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192, 15108153344) = 8192
pread64(24, "\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\1\4\0\0\0\5\202ob\204\3446\1"..., 8192, 15108157440) = 8192
pread64(24, "\0\0\0\0\0\1\1\4\0\0\0\5\202jb\204$:\1\0004\0\0\0e1cbec25"..., 8192, 15108161536) = 8192
pread64(24, "\1\0004\0\0\0e1cbec25-48d7-4b4a-a15c-74"..., 8192, 15108165632) = 8192
pread64(24, "a-a15c-74e0796f8b85.1775703.9925"..., 8192, 15108169728) = 8192
pread64(24, "85.1775670.9934077\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096, 15108173824) = 4096
pread64(24, "360.7680370204098643.jpg\0\334d(\355\3\0\0"..., 8192, 300595834880) = 8192
pread64(24, "85.1775670.9934077\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192, 15108173824) = 8192
pread64(24, "D\1\0004\0\0\0e1cbec25-48d7-4b4a-a15c-7"..., 8192, 15108177920) = 8192
pread64(24, "-4b4a-a15c-74e0796f8b85.1775667."..., 8192, 15108182016) = 8192
pread64(24, "74e0796f8b85.1786042.9947389\0\0\0\0"..., 8192, 15108186112) = 8192
pread64(24, "6054.9950927\0\0\0\0\0\0\0\0\0\0\0\0\0\0,#\251\00252"..., 8192, 15108190208) = 8192
pread64(24, "\0\0\0\0\0\0\0\0.!\251\0026230.967631592165436"..., 8192, 15108194304) = 8192
pread64(24, "283237922044.jpg\1\0\0\0\0\0\0\0\10\3\"\1\0\0;\0"..., 8192, 15108198400) = 8192
pread64(24, "pg\1\0\0\0\0\0\0\0\10\3$\1\0\0=\0\0\00059cf3eb6c9d2"..., 8192, 15108202496) = 8192
pread64(24, "#\1\0\0<\0\0\00059cf3eb6c9d2772cc4b7296c"..., 8192, 15108206592) = 8192
pread64(24, "75.jpg\0\20\206(\355\3\0\0.\"\0007710.4338298940"..., 8192, 300595838976) = 8192
pread64(24, "eb6c9d2772cc4b7296c/153122995536"..., 8192, 15108210688) = 8192
pread64(24, "5312299760800.18486374628905078."..., 4096, 15108214784) = 4096
pread64(24, "5312299760800.18486374628905078."..., 8192, 15108214784) = 8192
pread64(24, "\0\10\3#\1\0\0<\0\0\00059cf3eb6c9d2772cc4b72"..., 8192, 15108218880) = 8192

得到的这些东西，看起来是在操作bucket的元数据内容，这么一来就比较清楚了,再看看磁盘的io情况确认磁盘操作
iostat显示磁盘情况

对原理的猜测

ceph在删除数据的时候使用的是延时删除-回收机制，客户端发出删除文件请求后，ceph首先会把对象标记为被删除状态，然后等待GC线程来做下一步回收处理，这样做的好处是更充分利用系统资源；在rgw实际删除过程中，删除请求最终写入为一条删除某记录的数据，被存到rocksdb中，rocksdb使用的是树形结构，在插入的删除记录数引发level合并之后，就会引发大规模合并操作，导致osd不堪重负，如果pg分布不均匀，使得删除操作的压力总是在某个osd上，情况就更为严重，最终使得tp_osd_tp线程长期处于io状态，从而进一步引发心跳线程的僵死而被标记为down甚至被out

环境中，ssd-osd承载了除rgw.buckets.data之外的其他存储池，并且在四个节点下使用host的故障域，ssd-osd的存储池的pg未使用reweight进行重新分布，这就导致某个osd上index 池的pg数比其他osd高出近20，所以删除的大部分压力都集中在这个osd上了

由于环境所存放数据量太大，而且在集群运行时不宜进行故障域的更改和reweight

解决方案

为保证集群业务，我们将出问题的osd先彻底删除，数据恢复后，未再继续进行删除操作，集群可以维持稳定读取

在确认数据都可以丢弃之后，我们采取了重装集群的手段，重装进行了一些配置的改变，主要是这么几方面：
1、增加ssd-osd，原来一个节点只有两个，目前增加到四个，总数达到16个，保证压力的均摊，但两个ssd-osd使用同一个ssd盘
2、除了rgw.buckets.data池，其他存储池全部放到ssd-osd中，并且rgw.buckets.index的pg翻倍
3、对rgw.buckets.index池的pg进行reweight，使得它在所有osd中分布的数目差值不超过10
4、修改ssd-osd的故障域，从原来的host修改为磁盘柜box

重装集群后再进行性能测试评估，发现在硬件上加了几个ssd，策略和配置上做了调整之后，集群性能相比重装前翻倍，达到了165Kops，平均稳定在131Kops的水平，平均延时也更低，随后，我们将再次进行大规模数据删除的测试

本文作者： 奋斗的松鼠
本文链接： http://www.strugglesquirrel.com/2018/09/01/OSD失联引发持续pg异常处理/
版权声明： 本博客所有文章除特别声明外，创作版权均为作者个人所有，未经允许禁止转载！