procps-ng: top の Forest View と Graph

procps-ng のリポジトリの master をビルドして、 top を実行したらデフォルトの UI がガラっと変わっているのに気がついた

さらに A を押すとカラフル

以降調べたこと

Forest-View-Mode と Graph

プロセスをツリー状に表示するのは Forest View と呼ぶらしい

CPUやメモリのメーター表示は Graph と呼ぶらしい

コミットログ

Graph 表示を追加したのは以下のコミット (v.3.3.10 でリリース)

gitlab.com

デフォルトを Forest View に切り替えたのは以下のコミット (v.3.3.10 でリリース)

gitlab.com

注: Forest View 自体がどこで導入されたのかは追いきれてない

CentOS7

CentOS7.4 (1708) の top は procps-ng-3.3.10-16.el7 で、どちらも使える機能なのだが全く知らずに過ごしていた

理由を探るべくパッケージの spec ファイルを rpms/procps-ng.git - git.centos.org で確認したところ、以下のオプションによって 新しいモードをデフォルトでは使わない指定になっているのだった。 ΩΩΩ<ﾅ､ﾅﾝﾀﾞｯﾃｰ

            --disable-modern-top

RHEL の意向なのかなぁ。仕様をガラっと変えたくないとか

CentOS7 で新しいモード を有効にしたい場合

• top 起動
• V を押す ... Forest-View-Mode にする
• 1 を押す ... 論理CPU を全て表示する
• m を押す ... メモリの Graph を表示する
• t を押す ... CPU の Graph を表示する
• c を押す ... コマンドラインをフル表示する

とすると現在の master 版とほぼ同じ UI に変身する。繰り返すが全然知らなかったな

感想

• 手に馴染んで使ってるツールほど 新しい機能や良いやり方に気がつかないってのはあるある
• 強制的に新しいのにシフトさせることで再学習やアンラーニングを促す効果もあろう (Apple ぽい)
• 障害や不具合調査する際には top は必須コマンドだが、バージョンが違うとショートカットキーの違いで思うように操作できないことがあって、緊急時に困ったりはする

procps-ng / top は継続的に開発が続けられていて、新しいカーネルの仕様変更の追随や NUMA や LXC への対応や、現在は UTF-8 化などが進められている。今後の進化にも期待だ〜

鬼怒川〜日塩もみじライン〜塩原 🚲

11/4(土) 宇都宮〜鬼怒川〜もみじライン〜塩原を走ってきた。走行距離 104km, 獲得標高 1490m

午後に天気が荒れてしまったが ☔🌀 、紅葉のヒルクライムをたのしむことができた

util-linux の lsmem と chmem の素振り

util-linux のコミットを追いかけていて lsmem と chmem を見つけたので、なんとなしにコマンドの素振り ⚾

環境

• kernel 4.14.0-rc7-next-20171102
• util-linux の master ( 4707bc83e1ff6b634fb4ed38c8050b34fc2487a1 )

lsmem

lsmem で メモリブロック を一覧する

[vagrant@localhost util-linux]$ ./lsmem 
RANGE                                  SIZE  STATE REMOVABLE BLOCK
0x0000000000000000-0x0000000017ffffff  384M online        no   0-2
0x0000000018000000-0x000000001fffffff  128M online       yes     3
0x0000000020000000-0x0000000027ffffff  128M online        no     4
0x0000000028000000-0x000000002fffffff  128M online       yes     5
0x0000000030000000-0x000000003fffffff  256M online        no   6-7
0x0000000040000000-0x0000000047ffffff  128M online       yes     8
0x0000000048000000-0x000000004fffffff  128M online        no     9
0x0000000050000000-0x0000000057ffffff  128M online       yes    10
0x0000000058000000-0x00000000dfffffff  2.1G online        no 11-27
0x0000000100000000-0x000000011fffffff  512M online        no 32-35

Memory block size:       128M
Total online memory:       4G
Total offline memory:      0B

-J で JSON でも出せる。いまどきっぽい

[vagrant@localhost util-linux]$ ./lsmem -J
{
   "memory": [
      {"range": "0x0000000000000000-0x0000000017ffffff", "size": "384M", "state": "online", "removable": "no", "block": "0-2"},
      {"range": "0x0000000018000000-0x000000001fffffff", "size": "128M", "state": "online", "removable": "yes", "block": "3"},
      {"range": "0x0000000020000000-0x0000000027ffffff", "size": "128M", "state": "online", "removable": "no", "block": "4"},
      {"range": "0x0000000028000000-0x000000002fffffff", "size": "128M", "state": "online", "removable": "yes", "block": "5"},
      {"range": "0x0000000030000000-0x000000003fffffff", "size": "256M", "state": "online", "removable": "no", "block": "6-7"},
      {"range": "0x0000000040000000-0x0000000047ffffff", "size": "128M", "state": "online", "removable": "yes", "block": "8"},
      {"range": "0x0000000048000000-0x000000004fffffff", "size": "128M", "state": "online", "removable": "no", "block": "9"},
      {"range": "0x0000000050000000-0x0000000057ffffff", "size": "128M", "state": "online", "removable": "yes", "block": "10"},
      {"range": "0x0000000058000000-0x00000000dfffffff", "size": "2.1G", "state": "online", "removable": "no", "block": "11-27"},
      {"range": "0x0000000100000000-0x000000011fffffff", "size": "512M", "state": "online", "removable": "no", "block": "32-35"}
   ]
}

chmem でオフラインにする

REMOVABLE yes なメモリは offline にできるらしい。以下のコマンドを実行する

[vagrant@localhost util-linux]$ sudo ./chmem -d 0x0000000018000000-0x000000001fffffff 

... ところがどっこい、実行後 system 時間が 100% になって刺さってしまった。 perf top でみてみると __offline_pages というシンボルだった

ぬーん。strace(3) すると下記のようなシステムコールが並ぶ

access("/sys/devices/system/memory/memory0/valid_zones", F_OK) = 0
open("/sys/devices/system/memory/memory3/state", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=4096, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f16de7b5000
read(3, "online\n", 4096)               = 7
close(3)                                = 0
munmap(0x7f16de7b5000, 4096)            = 0
open("/sys/devices/system/memory/memory3/valid_zones", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f16de7b5000
read(3, "Movable\n", 4096)              = 8
close(3)                                = 0
munmap(0x7f16de7b5000, 4096)            = 0
open("/sys/devices/system/memory/memory3/state", O_WRONLY|O_CLOEXEC) = 3
write(3, "offline", 7 🔥

🔥 で刺さっとる

(推測)オフラインにする際にページを別のメモリブロックに移動したりするんだろけど、そこが大変なのだろか

別のレンジを offline にする

$ sudo ./chmem -d 0x0000000028000000-0x000000002fffffff

[vagrant@localhost util-linux]$ ./lsmem 
RANGE                                  SIZE   STATE REMOVABLE BLOCK
0x0000000000000000-0x0000000017ffffff  384M  online        no   0-2
0x0000000018000000-0x000000001fffffff  128M  online       yes     3
0x0000000020000000-0x0000000027ffffff  128M  online        no     4
0x0000000028000000-0x000000002fffffff  128M offline👈        -     5
0x0000000030000000-0x000000003fffffff  256M  online        no   6-7
0x0000000040000000-0x0000000047ffffff  128M  online       yes     8
0x0000000048000000-0x000000004fffffff  128M  online        no     9
0x0000000050000000-0x0000000057ffffff  128M  online       yes    10
0x0000000058000000-0x00000000dfffffff  2.1G  online        no 11-27
0x0000000100000000-0x000000011fffffff  512M  online        no 32-35

Memory block size:       128M
Total online memory:     3.9G
Total offline memory:    128M 👈

オンラインに戻すには以下の通り

sudo ./chmem -e 0x0000000028000000-0x000000002fffffff

感想

• Vagrant というか、VirtualBox でもメモリブロックの offline / online を試せておもろかった
• VirtualBox のメモリ割当ては一体どうなっているのだろう? 不思議なサイズのブロックが並んでいる

Linux Kernel: TASK_IDLE を調べる

本エントリの要約

Linux kenrel v4.14-rc3 から /proc/$pid/status と /proc/$pid/stat /proc/sched_debug で表示されるタスクの状態に I (idle) が追加されている

これに対応するカーネル内の定数は TASK_IDLE (注: 定数自体は v4.2-rc1 に追加された )

#define TASK_IDLE           (TASK_UNINTERRUPTIBLE | TASK_NOLOAD)

• TASK_IDLE は TASK_UNINTERRUPTIBLE の状態を取りつつも、 TASK_NOLOAD = ロードアベレージには寄与しない状態のタスクを示す
• TASK_IDLE は カーネルスレッドのみが取りうる状態のようだ ( kthreadd から生えた workqueue のスレッドや oom_reaper 等 )

ps や top で見るとカーネルスレッドの一部が I と表示されるのが確認できる

I のタスクを探してね

以降、調べた経緯を記す。興味ない人はすっ飛ばしてね

イントロダクション

kernel 4.14-rc7 を触っていたところ、 ps auxf で出力される STAT 欄に I で標示されるタスクがあるのに気がついた

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         2  0.0  0.0      0     0 ?        S    10月30   0:00 [kthreadd]
root         4  0.0  0.0      0     0 ?        I< 👈  10月30   0:00  \_ [kworker/0:0H]
root         6  0.0  0.0      0     0 ?        I< 👈 10月30   0:00  \_ [mm_percpu_wq]
root         7  0.0  0.0      0     0 ?        S    10月30   0:00  \_ [ksoftirqd/0]
root         8  0.0  0.0      0     0 ?        R    10月30   0:08  \_ [rcu_sched]
root         9  0.0  0.0      0     0 ?        I  👈 10月30   0:00  \_ [rcu_bh]
root        10  0.0  0.0      0     0 ?        S    10月30   0:00  \_ [migration/0]
root        11  0.0  0.0      0     0 ?        S    10月30   0:00  \_ [watchdog/0]

...

man で調べる

man 1 ps http://man7.org/linux/man-pages/man1/ps.1.html には載っていない

PROCESS STATE CODES         top

       Here are the different values that the s, stat and state output
       specifiers (header "STAT" or "S") will display to describe the state
       of a process:

               D    uninterruptible sleep (usually IO)
               R    running or runnable (on run queue)
               S    interruptible sleep (waiting for an event to complete)
               T    stopped by job control signal
               t    stopped by debugger during the tracing
               W    paging (not valid since the 2.6.xx kernel)
               X    dead (should never be seen)
               Z    defunct ("zombie") process, terminated but not reaped by
                    its parent

       For BSD formats and when the stat keyword is used, additional
       characters may be displayed:

               <    high-priority (not nice to other users)
               N    low-priority (nice to other users)
               L    has pages locked into memory (for real-time and custom
                    IO)
               s    is a session leader
               l    is multi-threaded (using CLONE_THREAD, like NPTL
                    pthreads do)
               +    is in the foreground process group

man 1 top http://man7.org/linux/man-pages/man1/top.1.html も同様で載っていない

       29. S  --  Process Status
           The status of the task which can be one of:
               D = uninterruptible sleep
               R = running
               S = sleeping
               T = stopped by job control signal
               t = stopped by debugger during trace
               Z = zombie

最近追加されたものだと推測できる。もしくは man 作ってる人達が見落としているってのもあるだろう (よくあるみたいだよ)

man の upstream を調べる

man 1 ps man 1 top の upstream は procps-ng だが、ここをみても (まだ) 説明は無かった

gitlab.com

gitlab.com

📝 rc 無しバージョンのカーネルがリリースされたら issue をあげたらいいかな?

strace で調べる

ps は /proc のデータを整形して出力するなのを経験的に知っているので、strace を取ってアタリをつけた

$ strace -yy -s100 -- ps ax -ostat 

...

stat("/proc/4", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0
open("/proc/4/stat", O_RDONLY)          = 6</proc/4/stat>
read(6</proc/4/stat>, "4 (kworker/0:0H) I 👈2 0 0 0 -1 69238880 0 0 0 0 0 0 0 0 0 -20 1 0 0 0 0 18446744073709551615 0 0 0 0 "..., 2048) = 
156
close(6</proc/4/stat>)                  = 0
open("/proc/4/status", O_RDONLY)        = 6</proc/4/status>
read(6</proc/4/status>, "Name:\tkworker/0:0H\nUmask:\t0000\nState:\tI (idle)\nTgid:\t4\nNgid:\t0\nPid:\t4\nPPid:\t2\nTracerPid:\t0\nUid:\t0\t0\t"..., 2048) = 893
close(6</proc/4/status>)                = 0
write(1</dev/pts/0>, "I<\n", 3I<　👈
)         = 3

/proc/$pid/stat もしくは /proc/$pid/status から取り出した文字列なのが分かる

[vagrant@localhost ~]$ cat /proc/4/stat
4 (kworker/0:0H) I 👈 2 0 0 0 -1 69238880 0 0 0 0 0 0 0 0 0 -20 1 0 0 0 0 18446744073709551615 0 0 0 0 0 0 0 2147483647 0 0 0 0 17 0 0 0 0 0 0 0 0 0 0 0 0 0 0

カーネルのソースを探す

The Linux Kernel Archives から最新のソースコードを取ってこよう。git blame で追いかけるならリポジトリを clone しておく方がよいか

github.com

/proc/$pid/stat や /proc/$pid/status のソースコードは fs/proc/*.c 以下に転がっている。適当に grep をかけて回って I は TASK_IDLE の省略形であることを調べだした。以下のコミットを探し出す

 $ grep idle fs/proc/* | head -1
fs/proc/array.c:    "I (idle)",     /* 0x80 */

ここをエントリポイントとして git blame でコミットを調べだして過去を遡っていく

関連のコミット

TASK_IDLE は下記のコミットで /proc/$pid/status /proc/$pid/stat に表示されるよになった ( v4.14-rc3 )

github.com

TASK_IDLE は下記のコミットで追加された ( v4.2-rc1 )

github.com

どういう用途なのかはコミットメッセージを読むと分かる

Currently people use TASK_INTERRUPTIBLE to idle kthreads and wait for 
'work' because TASK_UNINTERRUPTIBLE contributes to the loadavg. Having 
all idle kthreads contribute to the loadavg is somewhat silly. 

Now mostly this works OK, because kthreads have all their signals 
masked. However there's a few sites where this is causing problems and 
TASK_UNINTERRUPTIBLE should be used, except for that loadavg issue. 

This patch adds TASK_NOLOAD which, when combined with 
TASK_UNINTERRUPTIBLE avoids the loadavg accounting. 

As most of imagined usage sites are loops where a thread wants to 
idle, waiting for work, a helper TASK_IDLE is introduced. 

なるほどなー

感想

• 新しいステートが増えることで ps や /proc/pid/status , /proc/pid/stat をパースしてごそごそやっているツールがあれば副作用がでるだろうか?
  • とりあえずカーネルスレッドだけなので あまり影響はなさそうだが
• 些細な変更にみえるが、ユーザランドで確認できるステートが増えるというのは滅多にないことだよな
• TASK_UNINTERRUPTIBLE + TASKNO_LOAD にするのは興味深いが、そもそもロードアベレージの計算が TASK_RUNNING と TASK_UNINTERRUPTIBLE とで混ざっているのが厄介だよなぁ。Brendan Gregg は何と言ってたかな

www.brendangregg.com

rasdaemon のファイルディスクリプタリークを linux-edac ML に報告

id:buty4649 が業務で扱っている プライベートクラウド(OpenStack) に rasdaemon を導入してくれたのだけど、ハードウェアの異常を検知してはくれるものの sqlite にレコードを入れるあたりでエラーログを出していたので調べていた

Oct 19 16:06:42 *** rasdaemon[4233]: rasdaemon: Failed to do mc_event step on sqlite: error = 14
Oct 19 16:06:42 *** rasdaemon[4233]: rasdaemon: Failed reset mc_event on sqlite: error = 14

errno 14 は ENFILE で Too many open files 。よくみるやつ

       ENFILE          Too many open files in system (POSIX.1).  On Linux,
                       this is probably a result of encountering the
                       /proc/sys/fs/file-max limit (see proc(5)).

問題を起こしているプロセスの strace を取りつつ rasdaemon のソースを眺めてみたところ、abrtd にレポートを投げる関数があり その関数で socket(2) が成功してかつ connect(2) が失敗するとファイルディスクリプタがリークするというバグを見つた。その旨を linux-edac の ML にバグレポートを投げた

いきなりパッチを投げてもよさそうだが、まずはバグがあることを認識してもらうのがいいのだろうか。さてはて。

ややこしい状況

• 今回 rasaemon を動かしていたディストリビューションは Ubuntu
• abrtd は RedHat の提供するミドルウェアで Ubuntu 向けのパッケージは無い ( id:buty4649 調べ。++ )

... にもかかわらず

• Ubuntu の rasdaemon は abrtd にレポートを投げる ./configure --enable-abrt-report オプションを有効にしてビルドされている
• abrtd が動いていないので connect(2) は必ず失敗する
• つまりハードウェアの異常を検知すると 必ず 冒頭に述べたバグを踏む 🔥

というややこしい条件がついている感じだった。 「Ubuntu のひとたち rasdaemon 使ってないのネー」という話をした

その他調べたこと

• rasdaemon のメインリポジトリはここ git.infradead.org Git - users/mchehab/rasdaemon.git/summary
• rasdaemon のリリースやパッチは linux-edac の ML https://marc.info/?l=linux-edac に投稿されている

感想

• はやくバグ fix されるといいな

三宿 カフェ・プラスジョーヌ 🚲

天気が悪いので近所(?) を散歩でおしまい

走行距離 36.9km 。この位の距離だと、体をほぐす程度で疲れも残らず気分もさっぱり

チャリカフェさん のおすすめするお店リストを参考にして三宿のカフェ・プラスジョーヌに足を伸ばした

haveagood.holiday

カフェ・プラスジョーヌ

placejaune.com

窓際に自転車ラックがあるので 安心して御飯を食べられる。サラダが多めのカルボナーラか美味しかった。

店内にはツール・ド・フランスやロードバイク道具が溢れている

放送しているのはサッカー番組だったけどね。ロードレース観戦イベントもあるので また別の機会に

三軒茶屋を通り過ぎる際に、近所に住んでる上司と奥さんと赤ちゃんに遭遇。サイクルジャージ姿で声をかけたのでビックリさせたかなー。雨が降りかけていたのでちょっとばっかし立ち話をしてお別れ

KVM で VM を実行している際にホストの /proc/stat が返す user 時間についての注意点

KVM で VM を動かしている際に、ホストが返す /proc/stat 数値の扱いにはちょっとした注意が必要

/proc/stat の man

/proc/stat について説明した man 5 proc には下記の通りの説明がある

user (1) ユーザーモードで消費した時間。

guest (Linux 2.6.24 以降) (9) Linux カーネルの制御下のゲストオペレーティングシステムの仮想 CPU の 実行に消費された時間。

実はこの user には guest 分が重複して加算されている。そんでもって、この仕様は man には記載されていない。(英語の man でも同様)

ソースで説明

KVM で VM を動かしている際に消費した CPU時間を計測しているのは account_guest_time である。 (この記事を書いている時点で) 最新の 4.13-rc4 では下記の通りのソースだ

/*
 * Account guest cpu time to a process.
 * @p: the process that the cpu time gets accounted to
 * @cputime: the cpu time spent in virtual machine since the last update
 */
void account_guest_time(struct task_struct *p, u64 cputime)
{
    u64 *cpustat = kcpustat_this_cpu->cpustat;

    /* Add guest time to process. */
    p->utime += cputime;
    account_group_user_time(p, cputime);
    p->gtime += cputime;

    /* Add guest time to cpustat. */
    if (task_nice(p) > 0) {
        cpustat[CPUTIME_NICE] += cputime;
        cpustat[CPUTIME_GUEST_NICE] += cputime;
    } else {
        cpustat[CPUTIME_USER] += cputime; ⭐
        cpustat[CPUTIME_GUEST] += cputime; ⭐
    }
}

• cpustat[CPUTIME_USER] が user 時間
• cpustat[CPUTIME_GUEST] が guest 時間

両者に cputime を加算しているのがポイント

この計測方法は v2.6.24-rc1 から取り入れられている。その時の実装を貼る

/*
 * Account guest cpu time to a process.
 * @p: the process that the cpu time gets accounted to
 * @cputime: the cpu time spent in virtual machine since the last update
 */
void account_guest_time(struct task_struct *p, cputime_t cputime)
{
    cputime64_t tmp;
    struct cpu_usage_stat *cpustat = &kstat_this_cpu.cpustat;

    tmp = cputime_to_cputime64(cputime);

    p->utime = cputime_add(p->utime, cputime);
    p->gtime = cputime_add(p->gtime, cputime);

    cpustat->user = cputime64_add(cpustat->user, tmp); ⭐
    cpustat->guest = cputime64_add(cpustat->guest, tmp); ⭐
}

現在のと比較してリファクタリングされているのがわかるが、意味するところは変わらない

ユーザランドツールの実装をどうすべきか

mpstat を参考にする。先に述べた点を考慮して mpstat は user から guest を減算して補正している

https://github.com/sysstat/sysstat/blob/master/mpstat.c#L529-L568 (d7321c1)

/*
 ***************************************************************************
 * Display CPU statistics in JSON format.
 *
 * IN:
 * @tab        Number of tabs to print.
 * @g_itv  Interval value in jiffies multiplied by the number of CPU.
 * @prev   Position in array where statistics used as reference are.
 *     Stats used as reference may be the previous ones read, or
 *     the very first ones when calculating the average.
 * @curr   Position in array where current statistics will be saved.
 ***************************************************************************
 */
void write_json_cpu_stats(int tab, unsigned long long g_itv, int prev, int curr)
{
    struct stats_cpu *scc, *scp;
    unsigned long long pc_itv;
    int cpu, next = FALSE;

    xprintf(tab++, "\"cpu-load\": [");

    /* Check if we want global stats among all proc */
    if (*cpu_bitmap & 1) {

        next = TRUE;
        xprintf0(tab, "{\"cpu\": \"all\", \"usr\": %.2f, \"nice\": %.2f, \"sys\": %.2f, "
                  "\"iowait\": %.2f, \"irq\": %.2f, \"soft\": %.2f, \"steal\": %.2f, "
                  "\"guest\": %.2f, \"gnice\": %.2f, \"idle\": %.2f}",
             (st_cpu[curr]->cpu_user - st_cpu[curr]->cpu_guest) < ⭐
             (st_cpu[prev]->cpu_user - st_cpu[prev]->cpu_guest) ? ⭐
             0.0 :
             ll_sp_value(st_cpu[prev]->cpu_user - st_cpu[prev]->cpu_guest, ⭐
                     st_cpu[curr]->cpu_user - st_cpu[curr]->cpu_guest, ⭐
                     g_itv),

感想

• ソースを読んだら意外な事実が発覚することが Linux カーネルでは時折ある
• ところで KVM で VM を動かしてないなら /proc/stat の guest は増えないはずなので別に支障はない
• /proc/stat を読み取っても guest を捨てて計算しておいたら支障はない
  • sar は %guest を表示しない。どうやって計算しているんだろ?

root@test001:~# sar 1
Linux 4.4.0-66-generic (001)    10/11/17    _x86_64_    (48 CPU)

12:56:35        CPU     %user     %nice   %system   %iowait    %steal     %idle
12:56:36        all     18.37      0.00      4.31      0.19      0.00     77.13
12:56:37        all     29.69      0.00      5.02      0.32      0.00     64.98
12:56:38        all     24.02      0.00      4.08      0.38      0.00     71.52
12:56:39        all     31.86      0.00      3.62      0.29      0.00     64.22

エントリを書いたモチベーション

いつもお世話になっている GitHub の mackrelio/mackerel-agent にほぼ同様の内容で issue 報告していたのでした

github.com

mackerel に閉じた話題ではないので、 issue とは別の場所でもまとめておいたほうがいいだろうと思い本エントリを記した