喜迎
元旦
纸糊集群急救实录 | 奋斗的松鼠 - Blog

纸糊集群急救实录

字数统计: 3.6k字   |   阅读时长≈ 15分

还是这个脆弱的集群

写在前面

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

近期又有部分读者朋友催更ceph over RDMA(下)，看来大家对这个RDMA还是有点兴趣的，这里先透露一下当前的情况，RDMA的测试集群早前测试后，发现一个现象，当一个pool的osd超过1180个左右，osd就无法正常维持功能，经常down掉，然后松鼠哥就将这个集群又改回了默认的TCP方式，创建大比例EC的pool，用程序在灌数据，目前rados已经写入了36亿个对象，还在持续

关于RDMA，松鼠哥目前给出的看法是，比较难搞，所以摸索时间会长一些，但是我们并没有放弃，所以这个计划只是会延后一些，希望大家继续关注

本次更新的是一篇硬核干货，继上次纸糊集群拯救pg后，这次，这纸糊的集群又出事，而且是大事。

问题产生

这个问题产生得相当奇怪，同事在做常规的osd换盘重建，重建完后，正常的后续应该是集群慢慢回填数据，事实上这个集群因为是纸糊的，所以坏盘换盘都进行了几百次了，这操作没有导致过什么异常，但是这次更换坏盘重建osd后，业务告急，说整个集群的并发忽然大幅度降低！

现象

现象很明显，就是90%的osd都挂掉了，要么就一直在震荡！业务影响非常大，立刻切走！

这个环境大致情况是这样的

1
2
3
4
5
6
7
8
ceph mon are using a lot of disk space
osd: 2173 osds: 650 up, 2143 in; 13270 down pgs
       flags noout,noscrub,nodeep-scrub
  rgw: 20 daemons active
data:
  pools:   10 pools, 34056 pgs
  objects: 766.8 M objects, 2.3 PiB
  usage:   3.4 PiB used, 12 PiB / 15 PiB avail

2173个osds，一共72台机器，18台一个pool，数据量还挺大，7.6亿多，用ansible查了一下，几乎所有osd进程都在，但是很多是D状态的，dmesg日志是这么说的

1
[Thu Feb 24 18:16:44 2022] traps: ms_dispatch[782816] general protection ip:7fedbcc81a47 sp:7feda77dab20 error:0 in libc-2.17.so[7fedbcc4a000+1c2000]

竟然是traps，内核问题？再看下message

1
2
3
4
Feb 24 18:23:09 ceph-osd: *** Caught signal (Segmentation fault) **
Feb 24 18:23:09 ceph-osd: in thread 56003ef45690 thread_name:ms_dispatch
Feb 24 18:23:09 ceph-osd: src/tcmalloc.cc:284] Attempt to free invalid pointer 0x1
Feb 24 18:23:09 kernel: traps: ms_dispatch[782988] general protection ip:7f2b00fdfa47 sp:7f2aebb38b60 error:0 in libc-2.17.so[7f2b00fa8000+1c2000]

段错误，emm……难怪进程在但是是D状态的，看了下进程时间和id，大概几分钟就会重启一次，关键是2000多个osd同时这样，非常诡异

排查

所有ceph相关的进程都重启过了，没有用

看了下网络、时钟，也没有问题，看来不太会是环境导致

根据日志，推断非常有可能是bug，直接原因是tcmalloc.cc引用了无效指针，才被内核杀的，但是，如果是bug且无法搞好的话，问题就很严重了，这么大规模的集群，数据量这么大，如果所有osd都起不来了，无法读出数据，那么面临的将只有重建！丢失这么多数据这是不能接受的！

理论上讲，只要盘没有坏，没有进行格式化之类的数据清除操作，找回数据的概率还是很大的

正是因为有这样的理念，我们没有放弃

继续追查下去

突破

同事经过分析，认为进程被杀是因为osdmap加载有问题，osdmap刷下去的时候异常导致被杀，正常来讲osdmap不会发生这种事，但是稳妥起见我们还是看看osdmap有没有问题

导出一个osdmap看下

1
ceph osd getmap -o newosdmap

导出一下，这个osdmap有38M？？一个osdmap 38M是什么概念呢？看下隔壁正常集群的osdmap，同样导出后对比

1
2
3
4
[store@osd-036 ~]$ ls -l osdmap_503314
-rw-r----- 1 root root 39170644 Feb 24 23:20 osdmap_503314
[store@mon-001 ~]$ ls -l osdmap_552344
-rw-r----- 1 root root 1262198 Feb 24 21:19 osdmap_552344

这。。。故障集群的osdmap远远大于正常集群的osdmap，考虑到两个集群几乎完全一样的配置，相差38倍左右的大小显然是异常的！

继续看日志，发现每次osd启动到某个osdmap的epoch的时候，就卡住无法boot了

1
2
3
4
5
6
7
8
9
10
11
2022-02-24 22:40:45.284 7f763b8c0700 10 osd.1051 503273 _preboot _preboot mon has osdmaps 411575..503577
......
2022-02-24 22:41:02.066 7f764543c700 10 osd.1051 503273 handle_osd_map  got inc map for epoch 503312
2022-02-24 22:41:02.198 7f76520ed700 10 osd.1051 503273 tick_without_osd_lock
2022-02-24 22:41:02.428 7f764543c700 10 osd.1051 503273 handle_osd_map  got inc map for epoch 503313
2022-02-24 22:41:02.778 7f764543c700 10 osd.1051 503273 write_superblock sb(46b2bef0-9d6c-49eb-a147-083fb0cd18d8 osd.1051 46b1b8f8-2910-4cf2-8e8e-927b80b7e94f e503313 [411575,503313] lci=[93917,503273])
2022-02-24 22:41:03.203 7f76520ed700 10 osd.1051 503273 tick_without_osd_lock
2022-02-24 22:41:03.764 7f76350b3700  5 osd.1051 503273 heartbeat: osd_stat(1.3 TiB used, 6.1 TiB avail, 7.4 TiB total, peers [] op hist [])
2022-02-24 22:41:04.194 7f76520ed700 10 osd.1051 503273 tick_without_osd_lock
2022-02-24 22:41:05.172 7f76520ed700 10 osd.1051 503273 tick_without_osd_lock
2022-02-24 22:41:25.880 7f598eb0da00  0 set uid:gid to 167:167 (ceph:ceph)

可以看到，当osd启动后更新osdmap，到了503313后，就不再进行了，再过大约20秒，进程又再次重启，循环往复几十次，而当前集群最新的osdmap的epoch是503577，这就是说osd一直无法正常得到最新的osdmap

此前在《bluestore拯救pg》篇中松鼠哥处理过一个因为osdmap无法启动osd的问题，所以看着这个osdmap无法继续更新卡住的现象非常眼熟！但是，跟上次情况不同，上次是人为误操作修改了pg，范围影响是pg，而这次则严重得多，整个集群都塌了

那么出问题的到底是不是503314呢？为了看下osdmap从哪个epoch开始产生问题的，我们用ceph osd getmap 503xxx -o osdmap_503xxx的方式获取到多个osdmap，最终比对后发现，从503221开始，osdmap就从503220的850k变成了38M，但为什么不是503314有问题呢？只能猜测，503221的osdmap变大是出现了故障，但是这个故障并没有直接导致集群出问题，一直到503314，引发了致命的错误，实际上集群早有提示，ceph mon are using a lot of disk space，看了下mon的目录大概是19GiB，但是因为当时集群没有故障，因此以为是mon用了多一点磁盘空间而已，就没有深入追查，这样问题版本找出来了！

1
2
3
4
5
6
[store@osd-036 ~]$ ls -l osd*
-rw-r----- 1 root  root    852974 Feb 24 23:22 osdmap_503212
-rw-r----- 1 root  root    853209 Feb 24 23:23 osdmap_503218
-rw-r----- 1 root  root    853209 Feb 24 23:23 osdmap_503220
-rw-r----- 1 root  root  39151359 Feb 24 23:23 osdmap_503221
-rw-r----- 1 root  root  39151359 Feb 24 23:23 osdmap_503222

从现象上看大概率是osdmap异常引发集群宕掉，这也基本能解释为啥整个集群快速坍塌，因为整个集群72台机器几乎同时出现相同的故障，思路上，首先排除人为的错误配置下发，然后也不会是交换机集体故障，因为所有机器都能正常连通，而osdmap异常，就很有可能了，异常的osdmap可以很快地在整个集群中传播，使得所有osd几乎同时中招，当然这个情况也是第一次遇见!!

解决

osdmap的问题真的蛋疼。。。主要是这东西不太好搞

既然判断出osdmap某个epoch异常导致的故障，思路上，就是将osdmap回滚到一个正常的epoch！！osdmap回滚这可不是常规操作，ceph估计都没考虑过这个功能！但是为了客户的数据，我们还是要操作一波，风险系数较高，大家不要随意模仿

1、首先将所有ceph进程都down掉。

主要是防止各个ceph进程存在的osdmap干扰，所以先停进程保险一点

2、操作mon的rocksdb

首先查出mon的 rocksdb内osdmap的epoch都有哪些

1
2
3
4
5
6
7
8
9
ceph-kvstore-tool rocksdb /var/lib/ceph/mon/ceph-mon-001/store.db/ list|grep osdmap
...
osdmap 503566
osdmap 503577
......
osdmap	full_503566
osdmap	full_503577
osdmap	full_latest
osdmap	last_committed

可以看到osdmap的相关信息，get了一下内容发现很多，应该就是实际存储的osdmap

3、将故障epoch后面的所有epoch都删掉

确定要删除的epoch后，进行操作，将要删除的epoch弄出来写到脚本里面，最后将full_latest和last_committed修改为503220，如果不修改的话，mon会起不来，还要记得将rocksdb的sst所有者都改为ceph，因为sst被操作后所有者会变成root，不修改mon也起不来(踩过坑)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
#!/bin/bash
ndel='503221
503222
503223
....
full_503577'
for x in ${ndel}
do
    #echo ${x}
    ceph-kvstore-tool rocksdb /var/lib/ceph/mon/ceph-mon-002/store.db/ rm osdmap ${x}
done
ceph-kvstore-tool rocksdb /var/lib/ceph/mon/ceph-mon-002/store.db/ set osdmap full_latest ver 503220
ceph-kvstore-tool rocksdb /var/lib/ceph/mon/ceph-mon-002/store.db/ set osdmap last_committed ver 503220
chown ceph.ceph  /var/lib/ceph/mon/ceph-mon-002/store.db/*
4、启动mon

使用systemctl restart ceph-mon@mon-002.service，mon起来了，如法炮制，其他的mon也顺利起来，这样的话，查看集群的osdmap

1
2
3
4
5
6
ceph osd dump|more
epoch 503220
fsid 46b2bef0-9d6c-49eb-a147-083fb0cd18d8
created 2020-04-15 17:45:12.738276
modified 2022-02-25 00:00:37.710307
flags noout,noscrub,nodeep-scrub,sortbitwise,recovery_deletes,purged_snapdirs

osdmap回滚成功！！

5、处理osd

mon起来后，osdmap的epoch也回滚了，直接重启所有的osd，进程倒是都在，但是集群显示他们都没能上线。

看了下日志，发现是osd的osdmap epoch比mon还高

1
2022-02-25 09:42:07.778 7fac7bd3c700 10 osd.30 503281 _preboot _preboot mon has osdmaps 411575..503226

会不会是因为osd的osdmap版本太高，就没办法上线呢？看下代码怎么说的，从日志定位到代码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
void OSD::_preboot(epoch_t oldest, epoch_t newest)
{
  assert(is_preboot());
  dout(10) << __func__ << " _preboot mon has osdmaps "
	   << oldest << ".." << newest << dendl;

  // ensure our local fullness awareness is accurate
  heartbeat();

  // if our map within recent history, try to add ourselves to the osdmap.
  if (osdmap->get_epoch() == 0) {
    derr << "waiting for initial osdmap" << dendl;
  } else if (osdmap->is_destroyed(whoami)) {
    derr << "osdmap says I am destroyed" << dendl;
    // provide a small margin so we don't livelock seeing if we
    // un-destroyed ourselves.
    if (osdmap->get_epoch() > newest - 1) {
      exit(0);
    }
  } else if (osdmap->test_flag(CEPH_OSDMAP_NOUP) || osdmap->is_noup(whoami)) {
    derr << "osdmap NOUP flag is set, waiting for it to clear" << dendl;
  } else if (!osdmap->test_flag(CEPH_OSDMAP_SORTBITWISE)) {
    derr << "osdmap SORTBITWISE OSDMap flag is NOT set; please set it"
	 << dendl;
  } else if (osdmap->require_osd_release < CEPH_RELEASE_LUMINOUS) {
    derr << "osdmap require_osd_release < luminous; please upgrade to luminous"
	 << dendl;
  } else if (service.need_fullness_update()) {
    derr << "osdmap fullness state needs update" << dendl;
    send_full_update();
  } else if (osdmap->get_epoch() >= oldest - 1 &&
	     osdmap->get_epoch() + cct->_conf->osd_map_message_max > newest) {
    _send_boot();
    return;
  }

  // get all the latest maps
  if (osdmap->get_epoch() + 1 >= oldest)
    osdmap_subscribe(osdmap->get_epoch() + 1, false);
  else
    osdmap_subscribe(oldest - 1, true);
}

可以看到，_send_boot()之后，osd订阅mon的osdmap，而这个mon的osdmap epoch却是更低版本的，这就十分尴尬了-.-

思路上，有两个

第一，我们将所有osd的osdmap也回滚到503220或者更早，这样的话osd可以正常更新osdmap

这点，走不通，主要是osd的osdmap没法操作，查了一圈，发现有个方法可以设置osdmap

1
ceph-objectstore-tool --data-path /var/lib/ceph/osd/ceph-30/ --type bluestore --op set-osdmap --file osdmap_500000

但是，即使命令正常返回，osdmap实际上是没有设置成功的，这一点可以通过查看osd的superblock信息看到，而且，重启osd查看日志，也发现osdmap是没有更新到的

1
2
3
4
5
6
7
8
9
10
11
ceph-objectstore-tool --data-path /var/lib/ceph/osd/ceph-30/ --type bluestore --op dump-super
{
    "cluster_fsid": "46b2bef0-9d6c-49eb-a147-083fb0cd18d8",
    "osd_fsid": "eb7126cd-fd8e-4516-be3f-faff7f207e2c",
    "whoami": 30,
    "current_epoch": 503281,
    "oldest_map": 411575,
    "newest_map": 503226,
    "weight": 0.000000,
    ......
}

仿照mon的方式用ceph-kvstore-tool做行不行呢？也不行，因为osd的rocksdb跟mon不同，它只能导出来查看，没有办法修改它，说白了，就是osd的目录没有像mon一样的store.db目录，所以操作osd的rocksdb是很难的

第二，既然osdmap的epoch不能降，那能不能将mon的osdmap epoch升高呢？思路上当然是没有问题的，当前mon的osdmap的epoch是正常的，如果只是正常增大epoch，那么当mon的osdmap epoch大于osd时，osd应该就可以正常走启动流程了

那么，要增大mon(也就是集群)的osdmap，该怎么做呢？

其实要增大osdmap的epoch方法有很多，osdmap是描述osd在整个集群的分布及状态情况的，只要osd有变化，例如in或者out或者destroy，又或者新增osd，osdmap就会发生变化，更新epoch

所以，我们的操作，就仅仅是对一个已经out出集群，已经destroy的osd做in和out的操作，因为这样的osd对集群影响最小

1
for x in $( seq 0 50 ); do sudo ceph osd out osd.420  ;sleep 2;sudo ceph osd in osd.420;done

每in一次或者每out一次，osdmap就增加一个epoch，如此操作多次，使得集群的osdmap epoch超过了osd的osdmap epoch，然后重启osd，osd终于正常起来了！

经过一波操作，终于所有的osd都恢复了！！pg也随即全部active，调大恢复速度火力全开！

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
  pgs:     260261143/12253339657 objects degraded (2.124%)
           15569797/12253339657 objects misplaced (0.127%)
           24735 active+clean
           8370  active+undersized+degraded
           365   active+undersized+degraded+remapped+backfill_wait
           309   active+remapped+backfill_wait
           115   active+clean+remapped
           87    active+undersized+degraded+remapped+backfilling
           35    active+undersized+degraded+remapped+backfill_wait+backfill_toofull
           34    active+remapped+backfilling
           5     active+undersized+degraded+remapped
           1     active+remapped+backfill_wait+backfill_toofull
 
io:
  client:   19 MiB/s rd, 1.4 GiB/s wr, 4.54 kop/s rd, 4.54 kop/s wr
  recovery: 40.1 GiB/s, 11.31 kobjects/s

看到所有pg都active那一刻，这波力挽狂澜的辛苦没有白费！

总结

吐槽归吐槽，这个纸糊的集群虽然拉跨，但是提供了很多宝贵的动手机会不是吗？

在刚开始，一度以为集群遇到了内核的bug？或者是ceph版本的bug

但是随着调查的展开，发现是这样的情况，想着要回滚osdmap，机会渺茫啊-.-，但是操作下来，其实觉得也还行

目前我们仍未搞清楚osdmap为什么会从850k突增到38M，直接print它的内容并没有发现有什么问题，针对这个异常的osdmap的调查也还在继续，但是经过这波操作，我们也认识到了，回滚osdmap是可以做到的，而且最重要的是，只要磁盘没有坏掉，还能读写，没有进行格式化之类的数据清除操作，找回数据的概率还是很大的

赏

谢谢你请我吃糖果

支付宝
微信
  • 本文作者： 奋斗的松鼠
  • 本文链接： http://www.strugglesquirrel.com/2022/07/06/纸糊集群急救实录/
  • 版权声明： 本博客所有文章除特别声明外，创作版权均为作者个人所有，未经允许禁止转载！

扫一扫，分享到微信

tag:

    缺失模块。
    1、请确保node版本大于6.2
    2、在博客根目录（注意不是yilia-plus根目录）执行以下命令：
    npm i hexo-generator-json-content --save

    3、在根目录_config.yml里添加配置： 

      jsonContent:
    meta: false
    pages: false
    posts:
      title: true
      date: true
      path: true
      text: false
      raw: false
      content: false
      slug: false
      updated: false
      comments: false
      link: false
      permalink: false
      excerpt: false
      categories: false
      tags: true

松鼠哥，存储研发专家
曾就职于深信服北京研发中心，负责存储相关产品的调研测试
在分布式存储领域深耕近十年，实战经验和理论经验功力深厚
累计管理及上线生产集群超过600个，机器超3万台，磁盘总数超过80万块，总容量达到EB级别。