/proc/stat 的数据损坏引起的一个问题

昨晚九时左右,我们的 EC2 集群的监控系统触发了一条报警:

Alert: Instance xxx has high steal CPU usage (> 20%) for over 15 minutes

在云服务主机中,CPU steal time 并不少见。如果宿主机上其他的租户正在贪婪地运行 CPU-intensive 的任务,可能会抢占一部分本来属于你的虚拟机的时间,这些被抢占的时间就被报告为 steal time。

对于 AWS EC2 来说,情况有一点不同。AWS 使用 CPU Credit 来限制 EC2 实例的 CPU 使用,当实例过于频繁地使用 CPU,以至于超过了自身的 CPU Credit 配额,这个时候 steal time 就出现了。

问题排查

第一步当然是查清楚故障实例是否正在疯狂使用 CPU。登录 CloudWatch,检查该实例的 CPU 资源使用情况。发现这台实例的 CPU 使用率并不高,其 CPU Credit 配额十分富余。

这就相当于,你在银行还有一亿元存款,银行却告诉你,你破产了!

与此同时,我们的 Prometheus 监控系统给出了一些诡异的数据。

实例的 CPU idle time 直接掉到了 0(应该接近 100):

CPU idle time 掉到了 0

实例的 CPU steal time 升到了一个无法理解的巨大的数值(应该是 0):

CPU steal time 的数值完全没有意义

通过远程 SSH 登录该机器,检查系统的状况。逐项检查了系统的各项资源的使用情况,并没有发现资源使用率饱合的情况。系统中的服务也都运行正常。在终端多次运行命令 vmstat 1,输出的结果似乎也没有什么问题:

vmstat 1

不过,等一等,上面的输出中有两个诡异的地方:

  1. 每次运行命令的第一行输出中,CPU steal time (st) 的值总是接近 100(应该是 0 才对)
  2. 第一行之后的输出中,CPU idle time (id) 的值总是 0(应该接近 100 才对)

Hmmm,完全没有道理啊。

鉴于 vmstat 命令的 CPU 统计信息是从文件 /proc/stat 中读取的,下一步自然是检查这个文件。

这个文件的内容格式如下:

cpu  1085 316 940 770781 252 0 90 0 0 0
...

其中倒数第三项数字正是自系统启动以来的 CPU steal time 的累加值

好,打印十次文件内容,每次间隔 0.1 秒钟:

/proc/stat 文件的内容

注意看倒数第三列:应该是累加值才对啊,为什么数字在递减呢。难倒时间正在倒流?

既然时间不能倒流,那就只能是 /proc/stat 中的数据破损了。这个文件是由内核维护的。也就是说,是不是内核中统计 CPU steal time 的代码存在 bug?

搜寻一下 bug 数据库,在这个代码路径中果然有 bug:https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=871608这篇文章 描述得很清楚。

简单总结一下,如果宿主机遇到了硬件故障或者云服务商对虚拟机执行过 VM migrating 操作,就有可能触发这个 bug,导致虚拟机中的 CPU 计数器失效。

重启系统就能解除目前遇到的问题。不过,我想确认一下,这个问题到底是不是由宿主机引起的。

问题确认

向 AWS 提交工单,描述了我们遇到的问题。

几个小时之后,收到了 AWS 客服的回复,下面是回复内容:

Problem Description:
You find a wrong idle and stolen metrics in monitoring report, you want to know the reason and solution.

Diagnostic Analysis:

  1. Based on your description, I searched the instance details in our tool and the specific time (2018-02-06 13:25 UTC). I found there was a underlying hardware issue at the matched time and the issue has been fixed timely.
  2. Based on our back-end team's response, when the hardware issue happened, they had seen the abnormal stolen time happening on instances running kernel 4.9.XXX and above versions. I also checked instance xxx and found its kernel is 4.10.X.
  3. I am not sure whether the abnormal behavior is still exist in your instance. If the instance still meet the issue, please reboot the instance to recover. Since these are kernel counters after all, a reboot would reset everything and they will be back on track.

...

这就印证了我的猜测,确实是宿主机出现了问题。

问题解决

重启系统,问题解决。

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

推荐阅读更多精彩内容