Docker容器内ps输出CPU占用率全为0的解析

原创
05/28 18:38
阅读数 69

最近处理了一个ps输出的一个问题,主要涉及到的知识点有 /proc/[pid]/stat, /proc/stat, /proc/uptime, lxcfs, procps-ng等,为避免大家走弯路,特记录如下。

1、问题现象描述

在一个docker容器中:

top - 11:17:30 up 132 days,  1:21,  1 user,  load average: 11.28, 11.12, 10.96Tasks:  21 total,   1 running,  20 sleeping,   0 stopped,   0 zombie%Cpu(s): 39.8 us,  0.0 sy,  0.0 ni, 60.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 stKiB Mem : 16777216 total,  3797676 free,  9917836 used,  3061704 buff/cacheKiB Swap:        0 total,        0 free,        0 used.  6859380 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 507863 service   20   0   14.6g   9.2g  16584 S 293.8 57.6   7448:41 ads-union-adver 


可以看到,这个进程是有cpu占用的,但是使用如下命令查看:

#  ps -mp 507863 -o comm,THREAD,tid,time |head -10COMMAND         USER     %CPU PRI SCNT WCHAN  USER SYSTEM    TID     TIMEads-union-adver service   0.0   -    - -         -      -      - 5-04:29:33-               service   0.0  19    - futex_    -      - 507863 00:00:00-               service   0.0  19    - futex_    -      - 507865 00:00:09-               service   0.0  19    - futex_    -      - 507866 00:34:22-               service   0.0  19    - futex_    -      - 507867 00:00:00-               service   0.0  19    - futex_    -      - 507868 00:01:34-               service   0.0  19    - futex_    -      - 507869 00:04:28-               service   0.0  19    - futex_    -      - 507870 00:01:58-               service   0.0  19    - futex_    -      - 507871 00:14:40


在宿主机上查看对应的进程:

# ps -mp 502803 -o comm,THREAD,tid,time |head -10COMMAND         USER     %CPU PRI SCNT WCHAN USER SYSTEM   TID     TIMEads-union-adver service   283   -   - -         -     -     - 5-04:27:27-               service   0.0 19   - futex_   -     - 502803 00:00:00-               service   0.0 19   - futex_   -     - 502815 00:00:09-               service   1.3 19   - futex_   -     - 502822 00:34:21-               service   0.0 19   - futex_   -     - 502824 00:00:00-               service   0.0 19   - futex_   -     - 502825 00:01:34-               service   0.1 19   - futex_   -     - 502866 00:04:28-               service   0.0 19   - futex_   -     - 502867 00:01:58-               service   0.5 19   - futex_   -     - 502895 00:14:40

2、故障分析

一开始,我们以为是排序的问题,从输出看是从线程pid的大小来默认排序,但是看到总的cpu占用,在容器内和在容器外看到也不一样,一个为283,一个为0,所以事情必然有妖。然后查看ps的源码,发现计算cpu的函数为:

static int pr_pcpu(char *restrict const outbuf, const proc_t *restrict const pp){  unsigned long long total_time;   /* jiffies used by this process */  unsigned pcpu = 0;               /* scaled %cpu, 999 means 99.9% */  unsigned long long seconds;      /* seconds of process life */  total_time = pp->utime + pp->stime;--------计算当前进程的cpu占用时间  if(include_dead_children) total_time += (pp->cutime + pp->cstime);  seconds = cook_etime(pp);  if(seconds) pcpu = (total_time * 1000ULL / Hertz) / seconds;  if (pcpu > 999U)    return snprintf(outbuf, COLWID, "%u", pcpu/10U);  return snprintf(outbuf, COLWID, "%u.%u", pcpu/10U, pcpu%10U);}


需要查看cook_etime 的语义:

#define cook_etime(P) (((unsigned long long)seconds_since_boot >= (P->start_time / Hertz)) ? ((unsigned long long)seconds_since_boot - (P->start_time / Hertz)) : 0)


cook_etime的语义就是进程上电后到目前经历的秒数。

也就是算法大抵如下:

uptime  = total time system has been running.ps_time = process start time measured in seconds from boot.pu_time = total time process has been using the CPU.seconds   = uptime - ps_time---------------相当于进程生命周期总时长if(seconds)cpu_usage = pu_time * 1000 / seconds-------占用的cpu时间/生命周期print: cpu_usage / 10 "." cpu_usage % 10


整体看没有什么问题,然后实在不行上了gdb,我的ps版本是procps-ng-3.3.10。

发现seconds居然是0,seconds代表几个进程从上电后运行的秒数,怎么可能为0呢?

回到cook_etime这个宏的逻辑,当seconds_since_boot小于P->start_time的时候,seconds确实为0,下面就需要分析seconds_since_boot 为什么会小于P->start_time。

继续跟踪:

ps/global.c:395:  seconds_since_boot    = uptime(0,0);proc/sysinfo.c:94:int uptime(double *restrict uptime_secs, double *restrict idle_secs) {    double up=0, idle=0;    char *savelocale;
FILE_TO_BUF(UPTIME_FILE,uptime_fd);----这个UPTIME_FILE就是/proc/uptime savelocale = strdup(setlocale(LC_NUMERIC, NULL)); setlocale(LC_NUMERIC,"C"); if (sscanf(buf, "%lf %lf", &up, &idle) < 2) {-----up值为第一列 setlocale(LC_NUMERIC,savelocale); free(savelocale); fputs("bad data in " UPTIME_FILE "\n", stderr); return 0; } setlocale(LC_NUMERIC,savelocale); free(savelocale); SET_IF_DESIRED(uptime_secs, up); SET_IF_DESIRED(idle_secs, idle); return up; /* assume never be zero seconds in practice */}


看来是seconds_since_boot是通过读取/proc/uptime中的第一列的值获取的。

那么容器内的/proc/uptime是怎么获取的?

根据容器的信息:

                "Source": "/var/lib/baymax/lxcfs/proc/uptime",                "Destination""/proc/uptime",


可以知道容器内读取/proc/uptime,其实就是触发对宿主机对/var/lib/baymax/lxcfs/proc/uptime的访问,根据挂载信息:

# cat /proc/mounts |grep lxclxcfs /var/lib/baymax/lxcfs fuse.lxcfs rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other 0 0


可见其中经过一个lxcfs的转换,而且文件系统类型是fuse。

Fuse的使用再此不展开,我们知道在容器内对/proc/uptime的访问会演变成lxcfs的访问就行,它的值取决于容器的上电时间,对应uptime读取的调用链为:

proc_read-->proc_uptime_read,由于lxcfs的不停重构,以前在bindings.c的一些函数慢慢分散到proc_fuse.c等中去了,所以不列文件名,大家搜索一下就好。

感兴趣的同学可以阅读lxcfs源码:https://linuxcontainers.org/lxcfs

Ps: 如果你看代码仔细的话,你会发现docker容器内的/proc/uptime的第二列的语义也和宿主机不一致。

3、进一步分析

那么问题比较清晰了,seconds_since_boot 的在容器内值为容器上电之后经历的秒数,而start_time/Hertz是一个固定值,它指的是进程上电时间点系统启动时间点的一个差值,seconds_since_boot这个值和进程的start_time/Hertz比较,在宿主机没有问题是因为进程的start_time是以host的上电为基准时间经历的tick,这样就和seconds_since_boot的基准值是一样的;然而在docker容器中,这个基准就不存在了。Docker内获取的uptime和宿主机不一样,docker内的uptime是当前时间到docker内1号进程上电的一个差值。

# cat /proc/507863/stat |awk '{print $22}'1805091788
crash> task_struct.start_time,real_start_time ffff8c59d2220000 start_time = { tv_sec = 18050917, 这个单位是s,进程fork的时间点是host上电208天, tv_nsec = 885784324 } real_start_time = { tv_sec = 18050917, tv_nsec = 885784324 }
# docker ps |grep 82dc0fc1f82dc0fc1f1ff ee4752e24f05 "/usr/local/.baymax/…" 4 months ago Up 4 months k8s_fat-container_ads-union-show-svc-202001100955287243_ads-union-show-svc_46a40bbd-334c-11ea-81b7-8030e041f704_0
[root@10-128-119-26.ads-union-show-svc.cp01 .libs]# cat /proc/uptime 11317595.84 11317595.84  ----这个约为130天


130明显小于208,这样

#define cook_etime(P) (((unsigned long long)seconds_since_boot >= (P->start_time / Hertz)) ? ((unsigned long long)seconds_since_boot - (P->start_time / Hertz)) : 0)


按照这个宏就变成0了。

不过心里还有点小小的疑问,既然这个宏判断了seconds_since_boot 与P->start_time / Hertz的大小关系,是不是意味着存在某种可能两者关系不确定呢?是否因为秒的精度的问题?

然后尝试去看了一下git记录,之后了解到:

https://build.opensuse.org/package/view_file/Base:System/procps/procps-ng-3.3.8-accuracy.dif?expand=0

在如上地址的描述中,作者认为seconds的精度问题,将seconds修改成了jiffies,虽然在3.3.10没有合入这个补丁,但是很明显和本文的场景基准点问题不一样,所以略过不表。

然后查看到这个git记录:

-#define cook_etime(P) seconds_since_boot - (unsigned long)(P->start_time / Hertz)+#define cook_etime(P) (((unsigned long long)seconds_since_boot >= (P->start_time / Hertz)) ? ((unsigned long long)seconds_since_boot - (P->start_time / Hertz)) : 0)


这个就是3.3.10中当前代码的逻辑了,也就是作者当时这样保护可能还没有遇到容器这样的场景,只是简单将可能出现的负数设置为0.

然后查看比较新的3.3.16版本以及 https://gitlab.com/procps-ng 中最新的代码,也没有修复类似问题。

4、如何修改

我们能不能这样来修改:

在/proc/[pid]/stat中获取到第22列,也就是start_time,这个start_time是一个tick值,它表明的是进程上电的时间点,除以HZ然后我们再加上/proc/stat 中的btime。

# cat /proc/stat |grep btimebtime 1571822227


这样就获取了进程上电的绝对时间。其实这也就是pr_lstart函数的做法:

ps/output.c:970:static int pr_lstart(char *restrict const outbuf, const proc_t *restrict const pp){  time_t t;  t = getbtime() + pp->start_time / Hertz;  return snprintf(outbuf, COLWID, "%24.24s", ctime(&t));}


这样再获取当前时间再减去进程上电的时间,就获取了进程的生命周期了,然后利用进程的stat中的P->utime + P->stime除以生命周期,这样不也获得了这个比值么?

也就是如下修改:

  +struct timespec now;  total_time = pp->utime + pp->stime;  if(include_dead_children) total_time += (pp->cutime + pp->cstime);  -seconds = cook_etime(pp);  +if (clock_gettime(CLOCK_REALTIME, &now) < 0)  +  return -1;  +seconds = now.tv_sec-(pp->start_time / Hertz)-getbtime();


这样的补丁经过测试,是可以满足要求的,因为这时基准值已经统一了。有兴趣的同学可以给社区提交一下这个补丁。

参考文档:

http://www.wowotech.net/timer_subsystem/posix-clock.html
https://gitlab.com/procps-ng


作者 | 云平台高级工程师陈安庆


☆ END ☆


招聘信息

OPPO互联网云平台团队招聘一大波岗位,涵盖Java、容器、Linux内核开发、产品经理、项目经理等多个方向,请在公众号后台回复关键词“云招聘”查看查详细信息。


你可能还喜欢

一例 centos7.6 内核 hardlock 的解析

如何进行 kubernetes 问题的排障

OPPO自研ESA DataFlow架构与实践

客户端IPV6迁移适配——连接竞速算法Happy Eyeballs探索实践(一)

OPPO异地多活实践——缓存篇

OPPO自研代码审查系统火眼Code Review实践


更多技术干货

扫码关注

OPPO互联网技术

 

我就知道你“在看”

本文分享自微信公众号 - OPPO互联网技术(OPPO_tech)。
如有侵权,请联系 support@oschina.cn 删除。
本文参与“OSC源创计划”,欢迎正在阅读的你也加入,一起分享。

展开阅读全文
打赏
0
0 收藏
分享
加载中
更多评论
打赏
0 评论
0 收藏
0
分享
OSCHINA
登录后可查看更多优质内容
返回顶部
顶部