ps コマンドの %CPU がどのように計算されるかソースを追う (3) - top との算出方法の違い

hiboma.hatenadiary.jp

hiboma.hatenadiary.jp

上のエントリを書いみたものの、腑に落ちない疑問が残ったので、検証をしてみて整頓した

疑問

前回確かめたのはps%CPU が指すのは、プロセス(タスク) が開始してから消費した user 時間 + system 時間の割合だった。

  • ps が出すのは単位時間(例: 1秒とか ) あたりの CPU使用率 ではないよな? 一方で top は指定した間隔秒あたりの CPU使用率 を出すはず
  • ブロックする時間( sleep、ディスク I/O 、カーネル内のセマフォ等のロック待ち、スケジューラのレイテンシ, … ) が増えると、%CPU の数値は下がるよな?

… と疑問が残ってしまった。手を動かして確かめるのがよいだろう

検証

CPUバウンドなワンライナーCPU使用率pstop とで計測して、数値の違いを見ていく

検証環境

実行環境は macOS + VirtualBox + CentOS7.3 (kernel 4.13) で 2vCPU

検証 (1)

無限ループする perlワンライナーを実行する

perl -e '1 while 1'

ループ中はシステムコール呼び出しが無いので、Linux カーネルのスケジューラが割り当てたタイムクォンタムをまるっと usr 時間として消費するコードになる(よね?)

同時に、ps%CPU を計測する

while [ 1 ] do 
    echo $(date +"%s") $(ps -h -opcpu,pid,cmd -p $(pgrep perl))
    sleep 1
done

以下のようなデータが取れる。少し冗長だったか

1504612790 14765 95.0 perl -e 1 while 1
1504612791 14765 94.0 perl -e 1 while 1
1504612792 14765 94.0 perl -e 1 while 1
1504612793 14765 94.2 perl -e 1 while 1
1504612794 14765 94.2 perl -e 1 while 1
1504612795 14765 94.3 perl -e 1 while 1
1504612796 14765 94.4 perl -e 1 while 1
1504612797 14765 94.6 perl -e 1 while 1
1504612798 14765 94.6 perl -e 1 while 1
1504612800 14765 94.8 perl -e 1 while 1
1504612801 14765 95.0 perl -e 1 while 1

... 略

計測結果をプロットする

f:id:hiboma:20170906133531p:plain

92-95% 台で張り付いている

  • 時間が経つにつれて100%に向かって漸近するかと思ったが違ったようだ
  • 途中、数値が下がっている箇所もある。他のプロセス(計測のシェル・コマンド) やスケジューラのレイテンシ等々が作用しているのだろうか?
  • vCPU の数が2個なので増やしたら干渉が小さくなるようにも思う。

検証 (2)

最初に 5秒の sleep を挟んでから無限ループする perl を実行する。

# 5秒 sleep して 無限ループ
perl -e 'sleep(5); 1 while 1'

先ほどと同じく、ps で %CPU を取る

1504606214 0.0 12573 perl -e sleep(5); 1 while 1
1504606215 0.0 12573 perl -e sleep(5); 1 while 1
1504606216 0.0 12573 perl -e sleep(5); 1 while 1
1504606217 0.0 12573 perl -e sleep(5); 1 while 1
1504606218 0.0 12573 perl -e sleep(5); 1 while 1
1504606219 10.0 12573 perl -e sleep(5); 1 while 1
1504606220 21.8 12573 perl -e sleep(5); 1 while 1
1504606221 30.8 12573 perl -e sleep(5); 1 while 1
1504606222 38.0 12573 perl -e sleep(5); 1 while 1
1504606223 43.6 12573 perl -e sleep(5); 1 while 1
1504606225 48.2 12573 perl -e sleep(5); 1 while 1
1504606226 52.0 12573 perl -e sleep(5); 1 while 1

略 ....

データを整形して pandas でプロットする

f:id:hiboma:20170906131921p:plain

  • sleep した時間も含めて %CPU が計算されている様子がわかる。
  • 時間が経過するとともに sleep した時間が打ち消されて、90%台の数値にゆるやかに漸近していく

検証(3) top で %CPU を取る

ps との比較として top の検証もする

最初に 5秒の sleep を挟んでから無限ループする perl を実行する。

# 5秒 sleep して 無限ループ
perl -e 'sleep(5); 1 while 1'

top のバッチモード -b を使って1秒ごとの記録を取る

top -d 1 -b -p $(pgrep perl) | grep perl
  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
14657 vagrant   20   0  129668   3520   3192 S   0.0  0.1   0:00.00 perl
14657 vagrant   20   0  129668   3520   3192 S   0.0  0.1   0:00.00 perl
14657 vagrant   20   0  129668   3520   3192 S   0.0  0.1   0:00.00 perl
14657 vagrant   20   0  129668   3520   3192 S   0.0  0.1   0:00.00 perl
14657 vagrant   20   0  129668   3520   3192 R   8.0  0.1   0:00.08 perl
14657 vagrant   20   0  129668   3520   3192 R  92.1  0.1   0:01.01 perl
14657 vagrant   20   0  129668   3520   3192 R  93.0  0.1   0:01.94 perl
14657 vagrant   20   0  129668   3520   3192 R  91.1  0.1   0:02.86 perl

略 ...

top の %CPU は以下の意味である

k: %CPU  --  CPU 使用率
前回のスクリーン更新からの、タスクの所要 CPU 時間の占有率。

https://linuxjm.osdn.jp/html/procps/man1/top.1.html

データを整形して pandas でプロットする

f:id:hiboma:20170906131931p:plain

top は単位時間 ( スクリーン更新 の間隔) ごとに %CPU 使用率を算出しているので、最初に sleep でブロックした時間は後に算出する %CPU には影響していないのがわかる。 ( … グラフをプロットしなくても実行の推移を見てたらわかるだろうが。一応。 )

感想

  • ps の %CPU カラムの意味するところを今まで盛大に勘違いしていた。top ばっかり使ってるからなぁ (言い訳)
  • 「プロセスの CPU 使用率」とざっくりと問われた時に、ps, top それぞれどちらの計測の仕方を念頭においてるだろうか … ? 私は top の方をベースに考えていた節がある。
  • 算出方法の優劣があるわけではないので、場面に応じて使い分けるとよい
  • 名前からなんとなく意味を推し量ってしまい、知ったつもりでいるシステムメトリックの一例だろうか。深追いして調べてみると意味がぜんぜん違っていたりしてビックリする。( 例えばメモリの Active / Inactive は意味しているところを誤解されやすい )

おまけ: グラフをプロットしたコード

#!/usr/bin/env python3
# -*- coding: utf-8 -*-

import pandas as pd
import numpy as np
import seaborn

ts = pd.read_table("/tmp/data2", sep = " ", names = ["time", "pcpu"])

ax = ts[0:100].plot(ylim=[0, 105])
ax.yaxis.set_ticks(np.arange(0, 100+1, 5))
ax.xaxis.set_ticks(np.arange(0, 100+1, 5))
ax.set_xlabel("seconds")
ax.set_ylabel("%CPU")

ts = pd.read_table("/tmp/data.ps2", sep = " ", names = ["pcpu"])

ax = ts[0:100].plot(ylim=[0, 105])
ax.yaxis.set_ticks(np.arange(0, 100+1, 5))
ax.xaxis.set_ticks(np.arange(0, 100+1, 5))
ax.set_xlabel("seconds")
ax.set_ylabel("%CPU")

ts = pd.read_table("/tmp/data.top", sep = " ", names = ["pcpu"])

ax = ts[0:100].plot(ylim=[0, 105])
ax.yaxis.set_ticks(np.arange(0, 100+1, 5))
ax.xaxis.set_ticks(np.arange(0, 100+1, 5))
ax.set_xlabel("seconds")
ax.set_ylabel("%CPU")

ハードコードですいません