容器内就擷取個cpu使用率，怎麼就占用單核100%了呢
背景：這個是在centos7 + lxcfs 和jdk11 的環境上複現的
目前這個bug已經合入到了開源社群，
連結為 https://github.com/openjdk/jdk/pull/4378
下面列一下我們是怎麼排查并解這個問題的。
一、故障現象
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/360
lr-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 stat
tmpfs /proc/timer_stats tmpfs rw,nosuid,size=65536k,mode=755 0 0
lxcfs /proc/stat fuse.lxcfs rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other 0 0
lxcfs /proc/stat fuse.lxcfs rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other 0 0
lxcfs /proc/diskstats fuse.lxcfs rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other 0 0
很奇怪的是，發現有兩個挂載點都是/proc/stat，
嘗試手工讀取一下這個檔案：
# cat /proc/stat
cpu 12236554 0 0 9808893 0 0 0 0 0 0
cpu0 10915814 0 0 20934 0 0 0 0 0 0
cpu1 1320740 0 0 9787959 0 0 0 0 0 0
說明bash通路這個挂載點沒有問題，難道bash通路的挂載點和出問題的java線程通路的挂載點不是同一個？
檢視對應java打開的fd的super_block和mount，
crash> files 22345 |grep -w 360
360 ffff914f93efb400 ffff91541a16d440 ffff9154c7e29500 REG /rootfs/proc/stat/proc/stat
crash> inode.i_sb ffff9154c7e29500
i_sb = 0xffff9158797bf000
然後檢視對應程序歸屬mount的namespace中的挂載點資訊：
crash> mount -n 22345 |grep lxcfs
ffff91518f28b000 ffff9158797bf000 fuse lxcfs /rootfs/proc/stat
ffff911fb0209800 ffff914b3668e800 fuse lxcfs /rootfs/var/lib/baymax/var/lib/baymax/lxcfs
ffff915535becc00 ffff914b3668e800 fuse lxcfs /rootfs/proc/cpuinfo
ffff915876b45380 ffff914b3668e800 fuse lxcfs /rootfs/proc/meminfo
ffff912415b56e80 ffff914b3668e800 fuse lxcfs /rootfs/proc/uptime
ffff91558260f300 ffff914b3668e800 fuse lxcfs /rootfs/proc/stat/proc/stat
ffff911f52a6bc00 ffff914b3668e800 fuse lxcfs /rootfs/proc/diskstats
ffff914d24617180 ffff914b3668e800 fuse lxcfs /rootfs/proc/swaps
ffff911de87d0180 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_file
crash> fuse_file.fc 0xffff911e57b49b80
fc = 0xffff9158797be000
crash> 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_req
static 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
這行日志表明，當時解除安裝時出現失敗，不是所有的通路全部關閉。
三、故障複現
1.針對以上的懷疑點，寫了一個很簡單的demo如下：
#include <stdio.h>
#include <unistd.h>
#include <stdlib.h>
#define SCNd64 "I64d"
#define DEC_64 "%"SCNd64
static void next_line(FILE *f) {
while (fgetc(f) != '\n');//出錯的關鍵點
}
#define SET_VALUE_GDB 10
int 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 lxcfs
ffff88a5a2619800 ffff88a1ab25f800 fuse lxcfs /rootfs/proc/stat
ffff88cf53417000 ffff88a4dd622800 fuse lxcfs /rootfs/var/lib/baymax/var/lib/baymax/lxcfs
ffff88a272f8c600 ffff88a4dd622800 fuse lxcfs /rootfs/proc/cpuinfo
ffff88a257b28900 ffff88a4dd622800 fuse lxcfs /rootfs/proc/meminfo
ffff88a5aff40300 ffff88a4dd622800 fuse lxcfs /rootfs/proc/uptime
ffff88a3db2bd680 ffff88a4dd622800 fuse lxcfs /rootfs/proc/stat/proc/stat
ffff88a2836ba400 ffff88a4dd622800 fuse lxcfs /rootfs/proc/diskstats
ffff88bcb361b600 ffff88a4dd622800 fuse lxcfs /rootfs/proc/swaps
ffff88776e623480 ffff88a4dd622800 fuse lxcfs /rootfs/sys/devices/system/cpu/online
由于沒有關閉/proc/stat的fd，也就是進行大循環，然後這個時候重新開機lxcfs挂載：
#systemctl restart lxcfs
重新開機之後，發現挂載點資訊如下：
crash> mount -n 628957 |grep lxcfs
ffff88a5a2619800 ffff88a1ab25f800 fuse lxcfs /rootfs/proc/stat
ffff88a3db2bd680 ffff88a4dd622800 fuse lxcfs /rootfs/proc/stat/proc/stat------------這個挂載點，由于fd未關閉，是以解除安裝肯定失敗，可以看到super_block是重新開機前的
ffff887795a8f600 ffff88a53b6c6800 fuse lxcfs /rootfs/var/lib/baymax/var/lib/baymax/lxcfs
ffff88a25472ae80 ffff88a53b6c6800 fuse lxcfs /rootfs/proc/cpuinfo
ffff88cf75ff1e00 ffff88a53b6c6800 fuse lxcfs /rootfs/proc/meminfo
ffff88a257b2ad00 ffff88a53b6c6800 fuse lxcfs /rootfs/proc/uptime
ffff88cf798f0d80 ffff88a53b6c6800 fuse lxcfs /rootfs/proc/stat/proc/stat/proc/stat--------bind模式挂載，會新生成一個/proc/stat
ffff88cf36ff2880 ffff88a53b6c6800 fuse lxcfs /rootfs/proc/diskstats
ffff88cf798f1f80 ffff88a53b6c6800 fuse lxcfs /rootfs/proc/swaps
ffff88a53f295980 ffff88a53b6c6800 fuse lxcfs /rootfs/sys/devices/system/cpu/online
cpu立刻打到接近100%
628957 root 20 0 8468 612 484 R 98.8 0.0 18:40.92 caq.o
四、故障規避或解決
我們的解決方案是：
![Java小案例——随機數猜測随機數猜測[圖]](data:image/gif;base64,R0lGODlhAQABAIAAAP///wAAACwAAAAAAQABAAACAkQBADs=)