cgroup経由でシステムの利用状況を知る - CPU編

システム全体の負荷を計測する方法は、ロードアベレージ、topなどprocpsスイート、sysstat系のツールなど色々あるが、特定のコンテナ単位での負荷状況を知りたい。

コンテナ単位というのはつまり、cgroupの仕組みを用いて、一つのコンテナに所属しているプロセス群という形でグルーピングした単位を指す。人間は、その単位でリソースの利用を制限したり、その中での利用状況を取得したりできます。その仕組みをいじった結果を、今回整理しておく。

計測用のコンテナ

Haconiwa でこういう感じで作る。

# cgroup.haco
haconiwa = Haconiwa.define do |config|
  config.name = "stats-tester" # to be hostname
  config.init_command = ["/usr/bin/ruby", "-e", "def fib(n);n<2?1:fib(n-2)+fib(n-1);end;loop{puts fib(rand(32)+10); sleep 0.1}"]
  config.daemonize!

  root = Pathname.new("/var/lib/haconiwa/stats-tester")
  config.mount_independent "procfs"
  config.mount_independent "sysfs"
  config.mount_independent "devtmpfs"
  config.mount_independent "devpts"
  config.chroot_to root

  config.namespace.unshare "mount"
  config.namespace.unshare "ipc"
  config.namespace.unshare "uts"
  config.namespace.unshare "pid"

  config.cgroup :v1 do |cgroup|
    cgroup["cpuset.mems"] = "0"
    cgroup["cpuset.cpus"] = "0" # CPUは一つだけ利用する
    cgroup["cpu.cfs_period_us"] = 100000
    cgroup["cpu.cfs_quota_us"]  =  30000 # 30%の時間を使う
    cgroup["memory.limit_in_bytes"] = 128 * 1024 * 1024 # 128MB
  end

  config.add_general_hook :before_start_wait do |base|
    # memory.swappiness unsupported by mruby-cgroup...
    if system "echo 0 > /sys/fs/cgroup/memory/#{base.name}/memory.swappiness"
      Haconiwa::Logger.puts "memory.swappiness set to 0"
    end
  end
  #...
end

haconiwa run cgroup.haco として動かすと確かにコンテナのrubyプロセスは30%までしかCPUを使わない。

`cpuacct.usage`

このコンテナを動かしたままいくつかcgroupのレポートを見てみる。まず cpuacct.usage 。

vagrant@localhost:/sys/fs/cgroup$ while true; do echo "$(date): $(cat cpu,cpuacct/stats-tester/cpuacct.usage)"; sleep 1; done
Tue May  2 17:04:16 JST 2017: 7088420330
Tue May  2 17:04:17 JST 2017: 7389076422
Tue May  2 17:04:18 JST 2017: 7689779084
Tue May  2 17:04:19 JST 2017: 7985990294
Tue May  2 17:04:20 JST 2017: 8297153368
Tue May  2 17:04:21 JST 2017: 8588792999
Tue May  2 17:04:22 JST 2017: 8886689918
Tue May  2 17:04:23 JST 2017: 9192349465
Tue May  2 17:04:24 JST 2017: 9515864443
Tue May  2 17:04:25 JST 2017: 9806124279
Tue May  2 17:04:26 JST 2017: 10116934901
Tue May  2 17:04:27 JST 2017: 10407996217

これはそのグループの全てのプロセスの消費した総CPU時間が、ナノ秒単位で取得できる。このレポートは、 0 を書き込むとリセットできるので、前回の差分みたいな計算をしなくて済んで便利。

vagrant@localhost:/sys/fs/cgroup$ while true; do
>   echo 0 | sudo tee cpu,cpuacct/stats-tester/cpuacct.usage >/dev/null
>   sleep 1
>   echo "$(date): $(($(cat cpu,cpuacct/stats-tester/cpuacct.usage) / 1000000 ))" # ミリ秒に直す
> done 
Tue May  2 17:08:19 JST 2017: 299
Tue May  2 17:08:20 JST 2017: 306
Tue May  2 17:08:21 JST 2017: 299
Tue May  2 17:08:22 JST 2017: 298
Tue May  2 17:08:23 JST 2017: 307
Tue May  2 17:08:24 JST 2017: 246
Tue May  2 17:08:25 JST 2017: 302
Tue May  2 17:08:26 JST 2017: 301
Tue May  2 17:08:27 JST 2017: 218
Tue May  2 17:08:28 JST 2017: 300
Tue May  2 17:08:29 JST 2017: 300
Tue May  2 17:08:30 JST 2017: 300
Tue May  2 17:08:31 JST 2017: 301
Tue May  2 17:08:32 JST 2017: 299
Tue May  2 17:08:33 JST 2017: 299
Tue May  2 17:08:34 JST 2017: 310

バラつくけどだいたい、1000msの内300msになるということが確認出来る。システム全体の top などの値と違って、グループでまとまっての利用率がわかる。

`cpuacct.stat`

cpuacct.stat を使うと、CPUの利用時間のうちuser時間とsystem時間が別々にわかる。

vagrant@localhost:/sys/fs/cgroup$ while true; do date; echo '--------'; cat cpu,cpuacct/stats-tester/cpuacct.stat; echo; sleep 1; done
Tue May  2 17:11:40 JST 2017
--------
user 13780
system 2

Tue May  2 17:11:41 JST 2017
--------
user 13809
system 2

Tue May  2 17:11:42 JST 2017
--------
user 13839
system 2

Tue May  2 17:11:43 JST 2017
--------
user 13867
system 2

Tue May  2 17:11:44 JST 2017
--------
user 13897
system 2

今回はフィボナッチを計算し続けるようなプロセスなので、当然ほとんどuserに使われている。なお、この単位はカーネル内の USER_HZ 定数で割ると秒になる単位（クロック数）で、定数の値は以下のコマンドで取得できる。 man 7 time も参照。

vagrant@localhost:/sys/fs/cgroup$ ruby -retc -e "p Etc.sysconf(Etc::SC_CLK_TCK)"
100

1秒で30クロック増えてる、つまり、30 / 100 = 0.3秒のuser CPU時間を使っている。

`cpu.stat`

これは新しい概念が入ってきて、 cpu.cfs_period_us/cpu.cfs_quota_us 設定で非リアルタイムタスクの使うCPU時間を絞っているので、絞ったゆえに処理しきれなかった（スロットリングされた）回数や総時間がわかるとのこと。

vagrant@localhost:/sys/fs/cgroup$ while true; do date; echo '--------'; cat cpu,cpuacct/stats-tester/cpu.stat; echo; sleep 1; done
Tue May  2 17:25:36 JST 2017
--------
nr_periods 13033
nr_throttled 12756
throttled_time 897895440390

Tue May  2 17:25:37 JST 2017
--------
nr_periods 13044
nr_throttled 12767
throttled_time 898685422083

Tue May  2 17:25:38 JST 2017
--------
nr_periods 13054
nr_throttled 12777
throttled_time 899426628949

Tue May  2 17:25:39 JST 2017
--------
nr_periods 13064
nr_throttled 12787
throttled_time 900172116426

Tue May  2 17:25:40 JST 2017
--------
nr_periods 13074
nr_throttled 12797
throttled_time 900945918692

nr_periods は1秒に10増えている。 cfs_period_us が100ミリ秒であるため。

nr_throttled がスロットルされた回数、 throttled_time がスロットルされた総時間。 throttled_time をトラックしてみる。

vagrant@localhost:/sys/fs/cgroup$ while true; do echo "$(date): $(cat cpu,cpuacct/stats-tester/cpu.stat|grep throttled_time)"; sleep 1; done
Tue May  2 17:29:55 JST 2017: throttled_time 13885162836
Tue May  2 17:29:56 JST 2017: throttled_time 14648449581
Tue May  2 17:29:57 JST 2017: throttled_time 15241679862
Tue May  2 17:29:58 JST 2017: throttled_time 15994916934
Tue May  2 17:29:59 JST 2017: throttled_time 16637427322
Tue May  2 17:30:00 JST 2017: throttled_time 17339585163
Tue May  2 17:30:01 JST 2017: throttled_time 18117782852
Tue May  2 17:30:02 JST 2017: throttled_time 18799175343
Tue May  2 17:30:03 JST 2017: throttled_time 19499400817
Tue May  2 17:30:04 JST 2017: throttled_time 20201467360
Tue May  2 17:30:05 JST 2017: throttled_time 20904133327
Tue May  2 17:30:06 JST 2017: throttled_time 21629582846

例えば (20201467360 - 19499400817) / 1000_000.0 ~= 702.07 なので1秒あたり700ミリ秒分の処理がスロットルされている。これは30%の絞り込みとも合っている。

ここでクオータを以下のように大きくすると

cgroup["cpu.cfs_period_us"] = 100000
cgroup["cpu.cfs_quota_us"]  =  70000

vagrant@localhost:/sys/fs/cgroup$ while true; do echo "$(date): $(cat cpu,cpuacct/stats-tester/cpu.stat|grep throttled_time)"; sleep 1; done
Tue May  2 17:32:10 JST 2017: throttled_time 6874846831
Tue May  2 17:32:11 JST 2017: throttled_time 7173182175
Tue May  2 17:32:12 JST 2017: throttled_time 7471408688
Tue May  2 17:32:13 JST 2017: throttled_time 7730935446
Tue May  2 17:32:14 JST 2017: throttled_time 8036153139
Tue May  2 17:32:15 JST 2017: throttled_time 8326876176
Tue May  2 17:32:16 JST 2017: throttled_time 8640596457
Tue May  2 17:32:17 JST 2017: throttled_time 8930563825
Tue May  2 17:32:18 JST 2017: throttled_time 9225121733
Tue May  2 17:32:19 JST 2017: throttled_time 9546000058

(8930563825 - 8640596457) / 1000_000.0 ~= 289.97 という感じでスロットルされた時間が減る。最大が300ミリ秒までになる。

また、コンテナのRubyのコードを def fib;...;end;loop{puts fib(rand(32)); sleep 0.5} という感じに変更し、計算量を少なくすると、増加が緩やかになる。

vagrant@localhost:/sys/fs/cgroup$ while true; do echo "$(date): $(cat cpu,cpuacct/stats-tester/cpu.stat|grep throttled_time)"; sleep 1; done
Tue May  2 17:35:58 JST 2017: throttled_time 51572877
Tue May  2 17:35:59 JST 2017: throttled_time 51572877
Tue May  2 17:36:00 JST 2017: throttled_time 51572877
Tue May  2 17:36:01 JST 2017: throttled_time 174065818
Tue May  2 17:36:02 JST 2017: throttled_time 174065818
Tue May  2 17:36:03 JST 2017: throttled_time 174065818
Tue May  2 17:36:04 JST 2017: throttled_time 264314613
Tue May  2 17:36:05 JST 2017: throttled_time 313892798
Tue May  2 17:36:06 JST 2017: throttled_time 429919665
Tue May  2 17:36:07 JST 2017: throttled_time 429919665
Tue May  2 17:36:08 JST 2017: throttled_time 429919665
Tue May  2 17:36:09 JST 2017: throttled_time 429919665
Tue May  2 17:36:10 JST 2017: throttled_time 429919665
Tue May  2 17:36:11 JST 2017: throttled_time 429919665
Tue May  2 17:36:12 JST 2017: throttled_time 429919665
Tue May  2 17:36:13 JST 2017: throttled_time 537935003
Tue May  2 17:36:14 JST 2017: throttled_time 537935003

単位時間での throttled_time の増分を計測するのは、負荷の判断の基準の一つにできそう。

合わせて読みたい

DataDogさんの便利まとめ:

www.datadoghq.com

カーネルのドキュメント。cgroupの話を含むが、cgroup-v1配下にないので注意。

https://www.kernel.org/doc/Documentation/scheduler/sched-bwc.txt

同じようなノリでメモリやblkioも調べる。調べたいですね。

ローファイ日記

出てくるコード片、ぼくが書いたものは断りがない場合 MIT License としています http://udzura.mit-license.org/