容器内就获取个cpu利用率,怎么就占用单核100%了呢

背景:这个是在centos7 + lxcfs 和jdk11 的环境上复现的。

上面列一下咱们是怎么排查并解这个问题。

一、故障景象

OPPO内核团队接到jvm的兄弟甘兄发来的一个案例,景象是java的热点始终是如下函数,占比很高。

at sun.management.OperatingSystemImpl.getProcessCpuLoad(Native Method)

咱们受权后登陆oppo云宿主,发现top显示如下:

   PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                                       617248 service   20   0   11.9g   8.6g   9300 R 93.8  2.3   3272:09 java                                                                          179526 service   20   0   11.9g   8.6g   9300 R 93.8  2.3  77462:17 java     

二、故障景象剖析

java的线程,能把cpu使用率打这么高,常见个别是gc或者跑jni的死循环。从jvm团队反馈的热点看,这个线程应该在始终获取cpu利用率,而不是以前常见的问题。从perf的角度看,该线程始终在触发read调用。

而后strace查看read的返回值,打印如下:

read(360, 0x7f6f9000b000, 4096)         = -1 ENOTCONN (Transport endpoint is not connected)read(360, 0x7f6f9000b000, 4096)         = -1 ENOTCONN (Transport endpoint is not connected)read(360, 0x7f6f9000b000, 4096)         = -1 ENOTCONN (Transport endpoint is not connected)read(360, 0x7f6f9000b000, 4096)         = -1 ENOTCONN (Transport endpoint is not connected)read(360, 0x7f6f9000b000, 4096)         = -1 ENOTCONN (Transport endpoint is not connected)read(360, 0x7f6f9000b000, 4096)         = -1 ENOTCONN (Transport endpoint is not connected)

接着查看360这个fd到底是什么类型:

# ll /proc/22345/fd/360lr-x------ 1 service service 64 Feb  4 11:24 /proc/22345/fd/360 -> /proc/stat

发现是在读取/proc/stat,和下面的java热点读取cpu利用率是能吻合的。

依据/proc/stat在容器内的挂载点。

# cat /proc/mounts  |grep stattmpfs /proc/timer_stats tmpfs rw,nosuid,size=65536k,mode=755 0 0lxcfs /proc/stat fuse.lxcfs rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other 0 0lxcfs /proc/stat fuse.lxcfs rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other 0 0lxcfs /proc/diskstats fuse.lxcfs rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other 0 0

很奇怪的是,发现有两个挂载点都是/proc/stat。

尝试手工读取一下这个文件:

# cat /proc/statcpu  12236554 0 0 9808893 0 0 0 0 0 0cpu0 10915814 0 0 20934 0 0 0 0 0 0cpu1 1320740 0 0 9787959 0 0 0 0 0 0

阐明bash拜访这个挂载点没有问题,难道bash拜访的挂载点和出问题的java线程拜访的挂载点不是同一个?

查看对应java关上的fd的super_block和mount。

crash> files 22345 |grep -w 360360 ffff914f93efb400 ffff91541a16d440 ffff9154c7e29500 REG  /rootfs/proc/stat/proc/statcrash> inode.i_sb ffff9154c7e29500  i_sb = 0xffff9158797bf000

而后查看对应过程归属mount的namespace中的挂载点信息:

crash> mount -n 22345 |grep lxcfsffff91518f28b000 ffff9158797bf000 fuse   lxcfs     /rootfs/proc/statffff911fb0209800 ffff914b3668e800 fuse   lxcfs     /rootfs/var/lib/baymax/var/lib/baymax/lxcfsffff915535becc00 ffff914b3668e800 fuse   lxcfs     /rootfs/proc/cpuinfoffff915876b45380 ffff914b3668e800 fuse   lxcfs     /rootfs/proc/meminfoffff912415b56e80 ffff914b3668e800 fuse   lxcfs     /rootfs/proc/uptimeffff91558260f300 ffff914b3668e800 fuse   lxcfs     /rootfs/proc/stat/proc/statffff911f52a6bc00 ffff914b3668e800 fuse   lxcfs     /rootfs/proc/diskstatsffff914d24617180 ffff914b3668e800 fuse   lxcfs     /rootfs/proc/swapsffff911de87d0180 ffff914b3668e800 fuse   lxcfs     /rootfs/sys/devices/system/cpu/online

因为cat操作较短,写一个简略的demo代码,open 之后不敞开并且read 对应的/proc/stat门路,发现它拜访的挂载点的super_blcok是 ffff914b3668e800,因为代码极为简略,在此不列出。

也就是进一步地确认了,出问题的java过程拜访的是一个出问题的挂载点。那为什么拜访这个挂载点会返回ENOTCONN呢?

crash> struct file.private_data ffff914f93efb400  private_data = 0xffff911e57b49b80---依据fuse模块代码,这个是一个fuse_filecrash> fuse_file.fc 0xffff911e57b49b80  fc = 0xffff9158797be000crash> fuse_conn.connected 0xffff9158797be000  connected = 0

果然对应的fuse_conn的连贯状态是0,从打点看,是在fuse_get_req返回的。调用链如下:

sys_read-->vfs_read-->fuse_direct_read-->__fuse_direct_read-->fuse_direct_io    --->fuse_get_req--->__fuse_get_reqstatic struct fuse_req *__fuse_get_req(struct fuse_conn *fc, unsigned npages,                       bool for_background){...    err = -ENOTCONN;    if (!fc->connected)        goto out;...}

上面要定位的就是,为什么出问题的java线程会没有判断read的返回值,而不停重试呢?

gdb跟踪一下:

(gdb) bt#0  0x00007fec3a56910d in read () at ../sysdeps/unix/syscall-template.S:81#1  0x00007fec3a4f5c04 in _IO_new_file_underflow (fp=0x7fec0c01ae00) at fileops.c:593#2  0x00007fec3a4f6dd2 in __GI__IO_default_uflow (fp=0x7fec0c01ae00) at genops.c:414#3  0x00007fec3a4f163e in _IO_getc (fp=0x7fec0c01ae00) at getc.c:39#4  0x00007febeacc6738 in get_totalticks.constprop.4 () from /usr/local/paas-agent/HeyTap-Linux-x86_64-11.0.7/lib/libmanagement_ext.so#5  0x00007febeacc6e47 in Java_com_sun_management_internal_OperatingSystemImpl_getSystemCpuLoad0 ()   from /usr/local/paas-agent/HeyTap-Linux-x86_64-11.0.7/lib/libmanagement_ext.so

确认了用户态在循环进入 _IO_getc的流程,而后jvm的甘兄开始走查代码,发现有一个代码十分可疑:

UnixOperatingSystem.c:get_totalticks 函数,会有一个循环如下:

static void next_line(FILE *f) {    while (fgetc(f) != '\n');}

从fuse模块的代码看,fc->connected = 0的中央并不是很多,根本都是abort或者fuse_put_super调用导致,通过对照java线程升高的工夫点以及查看journal的日志,进一步fuse的挂载点生效有用户态文件系统lxcfs退出,而挂载点还有inode在拜访导致,导致又无奈及时地回收这个super_block,新的挂载应用的是:

remount_container() {    export f=/proc/stat    && test -f /var/lib/baymax/lxcfs/$f && (umount $f;  mount --bind /var/lib/baymax/lxcfs/$f $f)

应用了bind模式,具体bind的mount的个性能够参照网上的材料。

并且在journal日志中,查看到了要害的:

: umount: /proc/stat: target is busy

这行日志表明,过后卸载时呈现失败,不是所有的拜访全副敞开。

三、故障复现

针对以上的狐疑点,写了一个很简略的demo如下:

#include <stdio.h>#include <unistd.h>#include <stdlib.h>#define SCNd64 "I64d"#define DEC_64 "%"SCNd64static void next_line(FILE *f) {    while (fgetc(f) != '\n');//出错的关键点}#define SET_VALUE_GDB 10int main(int argc,char* argv[]){  unsigned long i =1;  unsigned long j=0;  FILE * f=NULL;  FILE         *fh;  unsigned long        userTicks, niceTicks, systemTicks, idleTicks;  unsigned long        iowTicks = 0, irqTicks = 0, sirqTicks= 0;  int             n;  if((fh = fopen("/proc/stat", "r")) == NULL) {    return -1;  }    n = fscanf(fh, "cpu " DEC_64 " " DEC_64 " " DEC_64 " " DEC_64 " " DEC_64 " "                   DEC_64 " " DEC_64,           &userTicks, &niceTicks, &systemTicks, &idleTicks,           &iowTicks, &irqTicks, &sirqTicks);    // Move to next line    while(i!=SET_VALUE_GDB)----------如果挂载点不变,则走这个大循环,单核cpu靠近40%    {       next_line(fh);//挂载点一旦变动,返回 ENOTCONN,则走这个小循环,单核cpu会靠近100%       j++;    }       fclose(fh);   return 0;}

执行以上代码,取得后果如下:

#gcc -g -o caq.o caq.c一开始独自运行./caq.o,会看到cpu占用如下:628957 root      20   0    8468    612    484 R  32.5  0.0  18:40.92 caq.o 发现cpu占用率时32.5左右,此时挂载点信息如下:crash> mount -n 628957 |grep lxcfsffff88a5a2619800 ffff88a1ab25f800 fuse   lxcfs     /rootfs/proc/statffff88cf53417000 ffff88a4dd622800 fuse   lxcfs     /rootfs/var/lib/baymax/var/lib/baymax/lxcfsffff88a272f8c600 ffff88a4dd622800 fuse   lxcfs     /rootfs/proc/cpuinfoffff88a257b28900 ffff88a4dd622800 fuse   lxcfs     /rootfs/proc/meminfoffff88a5aff40300 ffff88a4dd622800 fuse   lxcfs     /rootfs/proc/uptimeffff88a3db2bd680 ffff88a4dd622800 fuse   lxcfs     /rootfs/proc/stat/proc/statffff88a2836ba400 ffff88a4dd622800 fuse   lxcfs     /rootfs/proc/diskstatsffff88bcb361b600 ffff88a4dd622800 fuse   lxcfs     /rootfs/proc/swapsffff88776e623480 ffff88a4dd622800 fuse   lxcfs     /rootfs/sys/devices/system/cpu/online因为没有敞开/proc/stat的fd,也就是进行大循环,而后这个时候重启lxcfs挂载:#systemctl restart lxcfs重启之后,发现挂载点信息如下:crash> mount -n 628957 |grep lxcfsffff88a5a2619800 ffff88a1ab25f800 fuse   lxcfs     /rootfs/proc/statffff88a3db2bd680 ffff88a4dd622800 fuse   lxcfs     /rootfs/proc/stat/proc/stat------------这个挂载点,因为fd未敞开,所以卸载必定失败,能够看到super_block是重启前的ffff887795a8f600 ffff88a53b6c6800 fuse   lxcfs     /rootfs/var/lib/baymax/var/lib/baymax/lxcfsffff88a25472ae80 ffff88a53b6c6800 fuse   lxcfs     /rootfs/proc/cpuinfoffff88cf75ff1e00 ffff88a53b6c6800 fuse   lxcfs     /rootfs/proc/meminfoffff88a257b2ad00 ffff88a53b6c6800 fuse   lxcfs     /rootfs/proc/uptimeffff88cf798f0d80 ffff88a53b6c6800 fuse   lxcfs     /rootfs/proc/stat/proc/stat/proc/stat--------bind模式挂载,会新生成一个/proc/statffff88cf36ff2880 ffff88a53b6c6800 fuse   lxcfs     /rootfs/proc/diskstatsffff88cf798f1f80 ffff88a53b6c6800 fuse   lxcfs     /rootfs/proc/swapsffff88a53f295980 ffff88a53b6c6800 fuse   lxcfs     /rootfs/sys/devices/system/cpu/onlinecpu立即打到靠近100%628957 root      20   0    8468    612    484 R  98.8  0.0  18:40.92 caq.o     

四、故障躲避或解决

咱们的解决方案是:

1.在fgetc 中减少返回值的判断,不能无脑死循环。

2.因为lxcfs在3.1.2 的版本会有段谬误导致退出的bug,尽量降级到4.0.0以上版本,不过这个波及到libfuse动静库的版本适配。

3.在lxcfs等应用fuse的用户态文件系统进行remount的时候,如果遇到umount失败,则提早减轻试,超过次数通过日志告警零碎抛出告警。