ps コマンドの %CPU がどのように計算されるかソースを追う (2) - gdb で検証

hiboma.hatenadiary.jp

先のエントリでは ps コマンドのソースを読み、pr_cpu という関数で %CPU が計算されていると書いた。が、実行時に本当にその関数が呼び出されているのかどうかを確かめていなかった

ソースを誤読している可能性を排除するために、検証をしよう

gdb で検証

どういうアプローチで確かめるかを考えたが、gdb で調べてみたら良い感じだったので その手順をのせる

前準備

procps-ng の debuginfo パッケージを入れる

[vagrant@localhost ~]$ sudo debuginfo-install procps-ng
=====================================================================================================================================================================================
 Package                                                   アーキテクチャー               バージョン                                    リポジトリー                            容量
=====================================================================================================================================================================================
インストール中:
 glibc-debuginfo                                           x86_64                         2.17-157.el7_3.5                              base-debuginfo                         9.3 M
 ncurses-debuginfo                                         x86_64                         5.9-13.20130511.el7                           base-debuginfo                         1.1 M
 procps-ng-debuginfo                                       x86_64                         3.3.10-10.el7                                 base-debuginfo                         546 k
 systemd-debuginfo                                         x86_64                         219-30.el7_3.9                                base-debuginfo                          18 M
 yum-plugin-auto-update-debug-info                         noarch                         1.1.31-40.el7                                 base                                    26 k
依存性関連でのインストールをします:
 glibc-debuginfo-common                                    x86_64                         2.17-157.el7_3.5                              base-debuginfo                         9.4 M

トランザクションの要約
=====================================================================================================================================================================================
インストール  5 パッケージ (+1 個の依存関係のパッケージ)

gdb で ps を実行する

$ gdb $( which ps ) 

pr_pcpuブレークポイントをしかけよう。 (注: gdb に慣れていない人向けに省略記法をなるべく避けて記述する )

(gdb) break pr_pcpu
Breakpoint 1 at 0x405570: file output.c, line 499.

「ps で pid = 1 の %CPU を表示する」という引数で実行する

(gdb) run -o pcpu 1
Starting program: /usr/bin/ps -o pcpu 1
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
%CPU

Breakpoint 1, pr_pcpu (outbuf=0x7ffff7f9c090 "%CPU\n", pp=0x617840 <buf.6305>) at output.c:499
499    static int pr_pcpu(char *restrict const outbuf, const proc_t *restrict const pp){

ブレークポイントで停止した。pr_pcpu が呼び出されているのは間違いないようだ。

(gdb) backtrace 
#0  pr_pcpu (outbuf=0x7ffff7f9c090 "%CPU\n", pp=0x617840 <buf.6305>) at output.c:499
#1  0x0000000000407964 in show_one_proc (p=0x617840 <buf.6305>, fmt=0x63b370) at output.c:2026
#2  0x0000000000402eb8 in main (argc=4, argv=<optimized out>) at display.c:378

ソースコードをリストする。ちょっと行数がズレてる

(gdb) list
494      if(seconds) pcpu = (total_time * 100ULL / Hertz) / seconds;
495      if (pcpu > 99U) pcpu = 99U;
496      return snprintf(outbuf, COLWID, "%2u", pcpu);
497    }
498    /* normal %CPU in ##.# format. */
499    static int pr_pcpu(char *restrict const outbuf, const proc_t *restrict const pp){
500      unsigned long long total_time;   /* jiffies used by this process */
501      unsigned pcpu = 0;               /* scaled %cpu, 999 means 99.9% */
502      unsigned long long seconds;      /* seconds of process life */
503      total_time = pp->utime + pp->stime;

const proc_t *restrict const pp にプロセスの情報が入っているので、覗いてみよう。 pid = 1 ( systemd ) の /proc 以下のデータがまとまっている構造体だとわかる。

(gdb) print pp
$3 = (const proc_t * const) 0x617840 <buf.6305>

(gdb) p *pp
$2 = {tid = 1, ppid = 0, maj_delta = 0, min_delta = 0, pcpu = 0, state = 83 'S', pad_1 = 0 '\000', pad_2 = 0 '\000', pad_3 = 0 '\000', utime = 274, stime = 377, cutime = 2176, 
  cstime = 9878, start_time = 1, signal = '0' <repeats 16 times>, "\000", blocked = "7be3c0fe28014a03\000", sigignore = '0' <repeats 12 times>, "1000\000", 
  sigcatch = "00000001800004ec\000", _sigpnd = '0' <repeats 16 times>, "\000", start_code = 1, end_code = 1, start_stack = 0, kstk_esp = 0, kstk_eip = 0, 
  wchan = 18446744073709551615, priority = 20, nice = 0, rss = 969, alarm = 0, size = 0, resident = 0, share = 0, trs = 0, lrs = 0, drs = 0, dt = 0, vm_size = 45940, vm_lock = 0, 
  vm_rss = 3876, vm_data = 2344, vm_stack = 132, vm_swap = 988, vm_exe = 1296, vm_lib = 3640, rtprio = 0, sched = 0, vsize = 47042560, rss_rlim = 18446744073709551615, 
  flags = 4202752, min_flt = 70402, maj_flt = 308, cmin_flt = 3267216, cmaj_flt = 2059, environ = 0x0, cmdline = 0x0, cgroup = 0x0, supgid = 0x63b510 "-", supgrp = 0x0, 
  euser = '\000' <repeats 32 times>, ruser = '\000' <repeats 32 times>, suser = '\000' <repeats 32 times>, fuser = '\000' <repeats 32 times>, rgroup = '\000' <repeats 32 times>, 
  egroup = '\000' <repeats 32 times>, sgroup = '\000' <repeats 32 times>, fgroup = '\000' <repeats 32 times>, cmd = "systemd\000\000\000\000\000\000\000\000", ring = 0x0, 
  next = 0x0, pgrp = 1, session = 1, nlwp = 1, tgid = 1, tty = 0, euid = 0, egid = 0, ruid = 0, rgid = 0, suid = 0, sgid = 0, fuid = 0, fgid = 0, tpgid = -1, exit_signal = 17, 
  processor = 0, ns = {0, 0, 0, 0, 0, 0}, sd_mach = 0x0, sd_ouid = 0x0, sd_seat = 0x0, sd_sess = 0x0, sd_slice = 0x0, sd_unit = 0x0, sd_uunit = 0x0}

ブレークポイントから再開すると CPU使用率0.0 が表示して終了する

(gdb) continue
Continuing.
 0.0
[Inferior 1 (process 16371) exited normally]

こんなんでよいだろか

感想

  • ソースを読んだ上で、このような動作の検証を重ねておけば 勘違いや・誤りが無いことをたしかに出来るだろうか。実際に動かしてみたもので確かめないと不安になるというのは #ITエンジニアあるある