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

OPPO互联网技术 2020-09-24

2092

最近处理了一个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.96
Tasks:  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 st
KiB Mem : 16777216 total,  3797676 free,  9917836 used,  3061704 buff/cache
KiB 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 -10
COMMAND         USER     %CPU PRI SCNT WCHAN  USER SYSTEM    TID     TIME
ads-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 -10
COMMAND         USER     %CPU PRI SCNT WCHAN USER SYSTEM   TID     TIME
ads-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 lxc
lxcfs /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 82dc0fc1f
82dc0fc1f1ff        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 btime
btime 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互联网技术

我就知道你“在看”

docker

文章转载自OPPO互联网技术，如果涉嫌侵权，请发送邮件至：contact@modb.pro进行举报，并提供相关证据，一经查实，墨天轮将立刻删除相关内容。

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

1、问题现象描述

2、故障分析

3、进一步分析

4、如何修改

评论