11/4(土) 宇都宮〜鬼怒川〜もみじライン〜塩原を走ってきた。走行距離 104km, 獲得標高 1490m
午後に天気が荒れてしまったが ☔🌀 、紅葉のヒルクライムをたのしむことができた
続きを読む
util-linux のコミットを追いかけていて lsmem と chmem を見つけたので、なんとなしにコマンドの素振り ⚾
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"} ] }
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 🔥
🔥 で刺さっとる
(推測)オフラインにする際にページを別のメモリブロックに移動したりするんだろけど、そこが大変なのだろか
$ 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
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)
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 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 1 ps
man 1 top
の upstream は procps-ng だが、ここをみても (まだ) 説明は無かった
📝 rc 無しバージョンのカーネルがリリースされたら issue をあげたらいいかな?
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 しておく方がよいか
/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 )
TASK_IDLE は下記のコミットで追加された ( v4.2-rc1 )
どういう用途なのかはコミットメッセージを読むと分かる
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
をパースしてごそごそやっているツールがあれば副作用がでるだろうか?
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 にバグレポートを投げた
いきなりパッチを投げてもよさそうだが、まずはバグがあることを認識してもらうのがいいのだろうか。さてはて。
... にもかかわらず
./configure --enable-abrt-report
オプションを有効にしてビルドされているというややこしい条件がついている感じだった。 「Ubuntu のひとたち rasdaemon 使ってないのネー」という話をした
天気が悪いので近所(?) を散歩でおしまい
走行距離 36.9km 。この位の距離だと、体をほぐす程度で疲れも残らず気分もさっぱり
チャリカフェさん のおすすめするお店リストを参考にして三宿のカフェ・プラスジョーヌに足を伸ばした
窓際に自転車ラックがあるので 安心して御飯を食べられる。サラダが多めのカルボナーラか美味しかった。
店内にはツール・ド・フランスやロードバイク道具が溢れている
放送しているのはサッカー番組だったけどね。ロードレース観戦イベントもあるので また別の機会に
三軒茶屋を通り過ぎる際に、近所に住んでる上司と奥さんと赤ちゃんに遭遇。サイクルジャージ姿で声をかけたのでビックリさせたかなー。雨が降りかけていたのでちょっとばっかし立ち話をしてお別れ
KVM で VM を動かしている際に、ホストが返す /proc/stat
数値の扱いにはちょっとした注意が必要
/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),
/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 報告していたのでした
mackerel に閉じた話題ではないので、 issue とは別の場所でもまとめておいたほうがいいだろうと思い本エントリを記した