一次奇怪的 page cache 大量突然回收的 bug

这里记录一下前段时间排查的一个 bug。起因是这样,某个客户跟我们说他的 TiDB 集群时不时有延迟特别高的情况,然后我们通过监控排查,也确定了这个事情,于是开始排查。

首先我们需要确定这个是不是有定期的慢查询导致,但发现用户的业务场景其实比较固定,并没有慢查询。然后我们就继续排查了。

Page cache

在用户现场,一位同学发现伴随着延迟增加,用户机器上面的内存监控其实是有问题的,那段时间 page cache 被大量回收(20 GB+),然后 free memory 一下子多了很多。因为 page cache 少了,之前的很多 IO 操作需要重新读取磁盘,自然就慢了。然后另一位同学检查系统发现 VM 的 dirty_background_ratio 是 10,而 dirty_ratio 是 40,大家就怀疑也可能是 page cache 这个值有点大,占用了太多的 memory,导致了后面 page cache 被突然回收。

于是大家做了第一次改动,将 TiKV 里面 RocksDB 的 cache 调小,空出更多的可用内存,同时把 dirty_ratio 改成了 20。但问题依然存在。

Numa

然后我开始怀疑是否跟 NUMA 有关,毕竟之前在另一个用户那边遇到过一些 NUMA 的坑。于是使用 numactl 以及 numastats 看了看情况,发现用户一台机器部署了两个 TiKV,然后并没有将 TiKV 分别绑定到不同的 NUMA node 上面,通过 numastats 以及看两个 TiKV 自己的 numa map 文件,发现都是优先选择第一个 NUMA 节点来申请内存的。

在网上 Google 下,发现了几篇不错的文章 The MySQL “swap insanity” problem and the effects of the NUMA architecture Optimizing Linux Memory Management for Low-latency / High-throughput Databases Swap out problem on NUMA architecture 里面都提到了一些对 NUMA 的坑以及处理办法。

同时,我跟 Intel 的朋友讨论了一下,他建议最好绑定 NUMA,但另一方面,我们都觉得即使没有绑定,系统也不应该突然的回收这么多 page cache ,所以这个跟 NUMA 应该是没关系的,但绑定了应该是能提升性能的。

Pagecache Watermark

跟阿里云的朋友继续讨论了一下这个问题,他也觉得突然回收这么多是不可能的,所以建议我看看 pagecache 的 watermark,没准是跟一个系统的 bug Reduce system disruption due to kswapd V3 有关系,而正好,用户的系统没有打这个 patch。他建议我可以先把系统的 low 还有 high watermark 调整一下,让系统别这么快速的回收内存。

不过因为我之前没有操作过 watermark,所以还需要 Google 一下,看下到底如何调整。但我潜意识里面,仍然觉得,这个跟 watermark 没关系。

systemd-udevd

事情貌似陷入了死胡同,因为这个问题是随机出发的,我们摸不清楚规律,通过 sar 其实也也能看到那个时候有异常,但具体是啥就不知道了。这个时候,我采用了一个最原始的办法,直接启动了一个 pidstat,10s 输出一次,就跑在哪里,主要是我想知道出问题的时候到底是哪个进程在搞鬼。因为我发现,因为我发现,除开 pagecache 突然回收,另一个现象是 memory major fault 也增多,所以pidstat -r 10 走起。

终于出现了问题,然后我看了看 pidstat 的输出,特么的发现哪个时候竟然多出来一个进程,然后该进程名字跟我自己的一个产品名字一样,我当时只能觉得特么的这世界太多巧合了。然后进一步发现,出问题的时候,systemd-udevd 的 CPU 竟然飙高了,但正常情况下面,这个进程是绝对不可能这样的。通常,只有出现磁盘热拔插,触发相应的事件,才会让 systemd-udevd 工作的。

然后问了用户,才知道出问题的进程是云厂商的系统监控收集进程,会定期的收集系统信息,然后我好不容易找到这个进程所在的目录,翻了翻里面的日志,发现出问题的时候,日志里面有对 disk smartctl 的操作。于是问了云厂商的运维人员,他也糊涂了,觉得这个进程不可能影响服务。

但我觉得这个进程跟 systemd-udevd 突然工作是有关系的,于是打开了 udev 的 debug 日志,等到出问题的时候,发现 udev 在大量工作,尤其是不知道为啥在疯狂的重建 TiKV 所在磁盘的 table partition,看 log 是这个,但我因为不熟悉 udev,所以也不知道到底在干啥。但直觉上面,我觉得,这个就是导致 page cache 突然回收的问题,而 systemd-udevd 则是通过云厂商的这个进程触发的。

跟云厂商协调了一下,直接关掉了这个进程,然后整个世界清静了,问题没了。

结论

虽然解决了问题,但到现在为止,我也没明白为啥这个进程会触发 udev 工作,这个云厂商那边也没有结论,应该是他们自己从来没遇到过这样的问题,但实话,我们用户机器上面都部署了这个服务,影响还是蛮大的。

虽然这个问题不是我们的锅,把它找出来还是花了不少时间,走了一些弯路,但也学到了一些东西,首先我对 NUMA 理解更深了,所以后面一些在 NUMA 上面的测试,也知道如何 tune 了,另外就是对 page cache 这些也重新温习了一遍,再就是 sar 这种统计的还是有不足的地方,可能需要将 atop 这种服务也打开,至少能知道出问题的时候是哪些进程引起的,因为有些进程是短时进程,干完坏事就消失了。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 157,012评论 4 359
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 66,589评论 1 290
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 106,819评论 0 237
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 43,652评论 0 202
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 51,954评论 3 285
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,381评论 1 210
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,687评论 2 310
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,404评论 0 194
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,082评论 1 238
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,355评论 2 241
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 31,880评论 1 255
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,249评论 2 250
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 32,864评论 3 232
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,007评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,760评论 0 192
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,394评论 2 269
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,281评论 2 259

推荐阅读更多精彩内容