HackToTech

Hack To Technology

BPF本を読みながら学ぶ7

7章、 メモリについて
仮想・物理のそれぞれについて理解がまた一段と深まった
昔作ったメモリリークアプリが役に立ったのが地味に嬉しい

目次

用語

  • backed by disk
    • ディスクから読み出されて変更のなかったページ
  • brk syscall
    • 渡した値が現在の値を下回った場合、ヒープの領域の開放が行われる
    • 渡した値が現在の値を上回った場合、ヒープの領域の拡張が行われる(失敗するとENOMEM)

メモリのパフォーマンス分析

  1. システムメッセージをチェックして、最近にOOMキラーがプロセスを強制終了したかどうかを確認する dmesg
  2. システムにスワップデバイスがあるかどうか、及び使用中のスワップの量を確認する(それらのデバイスに対してのアクティブなI/Oがあるかも確認する) swapon -s / free / vmstat / iostat
  3. システム上の空きメモリの量とキャッシュによるシステム全体の使用量を確認する
  4. プロセスごとのメモリ使用量を確認する top / ps axo user,pid,pmem,vsz,rsz,comm
  5. ページフォールトのレートを確認し、ページフォールトのスタックトレースを調べる これでRSSの増加については説明ができる(ページフォールトする箇所のコードでヒットしなかった場合に物理メモリの確保を行うからだと思われ)
  6. ページフォールトしていたファイルを調べる
  7. brkとmmapのsyscallをトレースして、メモリ使用量のビューを取得する
  8. BPFツールを使用して実行する
  9. PMCを使用してハードウェアキャッシュミスとメモリアクセスを確認し、メモリI/Oを引き起こす関数と命令を特定する perf

swapon

スワップデバイスの構成及び使用中のボリュームの量を表示する

❯ swapon -s
Filename        Type    Size  Used  Priority
/dev/sda5                               partition 5661692 0 -2

ps

プロセスごとのメモリ使用量を確認する

❯ ps axo user,pid,pmem,vsz,rsz,comm | head -n10
USER        PID %MEM    VSZ   RSZ COMMAND
root          1  0.1 225492  9328 systemd
root          2  0.0      0     0 kthreadd
root          3  0.0      0     0 rcu_gp
root          4  0.0      0     0 rcu_par_gp
root          6  0.0      0     0 kworker/0:0H-kb
root          8  0.0      0     0 mm_percpu_wq
root          9  0.0      0     0 ksoftirqd/0
root         10  0.0      0     0 rcu_sched
root         11  0.0      0     0 migration/0

pmap

アドレス空間ごとのプロセスのメモリ使用量の表示
Dirtyのカラムは、メモリ内で変更されてディスク側へ保存されていないページサイズ

❯ pmap -x 8998
// 一部省略
8998:   node server.js
Address           Kbytes     RSS   Dirty Mode  Mapping
0000000000400000   31320   22132       0 r-x-- node
0000000000400000       0       0       0 r-x-- node
0000000002495000       8       8       8 r---- node
0000000002495000       0       0       0 r---- node
0000000002497000      84      84      32 rw--- node
0000000002497000       0       0       0 rw--- node
00000000024ac000     104     100     100 rw---   [ anon ]
00007f631b198000       4       0       0 -----   [ anon ]
00007f631b198000       0       0       0 -----   [ anon ]
00007f631ccf3000       4       4       4 rw--- libdl-2.27.so
00007f631ccf3000       0       0       0 rw--- libdl-2.27.so
00007f631ccf4000     156     156       0 r-x-- ld-2.27.so
00007f631ccf4000       0       0       0 r-x-- ld-2.27.so
00007ffd501d2000     136      56      56 rw---   [ stack ]
00007ffd501d2000       0       0       0 rw---   [ stack ]
00007ffd501fe000       0       0       0 r-x--   [ anon ]
ffffffffff600000       4       0       0 r-x--   [ anon ]
ffffffffff600000       0       0       0 r-x--   [ anon ]
---------------- ------- ------- ------- 
total kB          575736   52096   25988

sar

フィールド

pgpgin/s システムが1秒間にディスクからページインしたキロバイトの合計
pgpgout/s システムが1秒間にディスクにページアウトしたキロバイトの合計
fault/s システムによって1秒間に発生したページフォールト(major + minor)の回数. 一部のページフォールトはI/Oなしで解決できる為、これはI/Oが発生するページフォールトの回数ではない.
majflt/s システムが1秒間に行ったメジャーフォールトの(ディスクからメモリへページを読み込む必要があった)回数
pgfree/s システムによって1秒間に空きリストに配置されたページの数
pgscank/s kswapdデーモンによって1秒間にスキャンされたページの数
pgscand/s 1秒間に直接スキャンされたページ数
pgsteal/s メモリへの要求を満たすためにシステムが1秒間にキャッシュ(pagecache/swapcache)から回収したページ数
%vmeff ページ再利用の指標(一定時間内にページがスキャンされなかった場合、このフィールドはゼロとして表示される)
❯ sar -B 1
Linux 5.0.0-36-generic (ubuntu)   12/01/2019  _x86_64_  (4 CPU)

04:58:42 PM  pgpgin/s pgpgout/s   fault/s  majflt/s  pgfree/s pgscank/s pgscand/s pgsteal/s    %vmeff
04:58:43 PM      0.00      0.00      1.00      0.00     13.00      0.00      0.00      0.00      0.00
04:58:44 PM      0.00      0.00     23.00      0.00     24.00      0.00      0.00      0.00      0.00
^C

Average:         0.00      0.00     12.00      0.00     18.50      0.00      0.00      0.00      0.00

oomkill

カーネルのOOMKillerをトレースし、強制終了時のシステム負荷平均などの基本的な詳細を出力する

# これでOOMKillされる優先順位をあげる
❯ sudo echo 1000 > /proc/18169/oom_score_adj

# 優先順位の確認
❯ dstat --top-oom
--out-of-memory---
    kill score    
node          1.0k

# リクエストを投げつけてメモリの確保を大量にさせる(内容としては、投げつけたsize分のランダムに生成したバイトをglobalのarrayにpushしている)
❯ curl localhost:3000/?size=2147483647
{"rss":1160204288,"heapTotal":16543744,"heapUsed":11553040,"external":34359797528}

# 別タブで観測しておく
❯ sudo /usr/share/bcc/tools/oomkill 
Tracing OOM kills... Ctrl-C to stop.
22:47:29 Triggered by PID 18854 ("node"), OOM kill of PID 18169 ("node"), 2035372 pages, loadavg: 2.77 1.29 0.69 6/714 19862
^C

memleak

メモリリークを検出するために、未解決の割り当てとその呼び出しのスタックのサマリを出力する

# リクエストを投げつけてメモリの確保をさせる
❯ curl localhost:3000/?size=2147483
{"rss":51503104,"heapTotal":24977408,"heapUsed":17034168,"external":2430550}

# 別タブでnodeのprocessにアタッチさせておく
❯ sudo /usr/share/bcc/tools/memleak -p 20294
Attaching to pid 20294, Ctrl+C to quit.
[22:55:08] Top 10 stacks with outstanding allocations:

  2147483 bytes in 1 allocations from stack
    v8::internal::JSArrayBuffer::SetupAllocatingData(v8::internal::Handle<v8::internal::JSArrayBuffer>, v8::internal::Isolate*, unsigned long, bool, v8::internal::SharedFlag)+0x93 [node]
    v8::internal::(anonymous namespace)::ConstructBuffer(v8::internal::Isolate*, v8::internal::Handle<v8::internal::JSFunction>, v8::internal::Handle<v8::internal::JSReceiver>, v8::internal::Handle<v8::internal::Object>, bool)+0x74 [node]
    v8::internal::Builtin_ArrayBufferConstructor(int, v8::internal::Object**, v8::internal::Isolate*)+0xa3 [node]
    [unknown]
    [unknown]
    [unknown]
    v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*)+0x103 [node]
    v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*)+0x179 [node]
    node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context)+0x1b2 [node]
    node::Environment::CheckImmediate(uv_check_s*)+0xbc [node]
    uv__run_check+0x8c [node]
    uv_run+0x153 [node]
    node::Start(v8::Isolate*, node::IsolateData*, std::vector<std::string, std::allocator<std::string> > const&, std::vector<std::string, std::allocator<std::string> > const&)+0x565 [node]
    node::Start(int, char**)+0x469 [node]
    __libc_start_main+0xe7 [libc-2.27.so]
    [unknown]

shmsnoop

SystemV共有メモリのシステムコールをトレースする
対象はshmget, shmat, shmdt, shmctl っぽい

フィールド

PID プロセスID
COMM コマンド名(親プロセス)
SYS syscall
RET syscallの戻り値
ARGs syscallの引数
❯ sudo /usr/share/bcc/tools/shmsnoop
PID    COMM                SYS              RET ARGs
1243   Xorg              SHMAT     7fe099431000 shmid: 0x1b8004, shmaddr: 0x0, shmflg: 0x0
1243   Xorg             SHMCTL                0 shmid: 0x1b8004, cmd: 2, buf: 0x7ffd1012f130
1243   Xorg              SHMDT                0 shmaddr: 0x7fe099431000
1243   Xorg              SHMAT     7fe099431000 shmid: 0x1c0004, shmaddr: 0x0, shmflg: 0x0
1243   Xorg             SHMCTL                0 shmid: 0x1c0004, cmd: 2, buf: 0x7ffd1012f130
1243   Xorg              SHMDT                0 shmaddr: 0x7fe099431000
3209   gnome-shell      SHMGET           1c8004 key: 0x0, size: 49152, shmflg: 0x3ff (IPC_CREAT|0777)
3209   gnome-shell       SHMAT     7effebf5b000 shmid: 0x1c8004, shmaddr: 0x0, shmflg: 0x0
3209   gnome-shell      SHMCTL                0 shmid: 0x1c8004, cmd: 0, buf: 0x0
1243   Xorg              SHMAT     7fe099426000 shmid: 0x1c8004, shmaddr: 0x0, shmflg: 0x0
1243   Xorg             SHMCTL                0 shmid: 0x1c8004, cmd: 2, buf: 0x7ffd1012f130
3209   gnome-shell      SHMGET           1d000f key: 0x0, size: 32768, shmflg: 0x3ff (IPC_CREAT|0777)
3209   gnome-shell       SHMAT     7effebf53000 shmid: 0x1d000f, shmaddr: 0x0, shmflg: 0x0
3209   gnome-shell      SHMCTL                0 shmid: 0x1d000f, cmd: 0, buf: 0x0
1243   Xorg              SHMAT     7fe09941e000 shmid: 0x1d000f, shmaddr: 0x0, shmflg: 0x0
1243   Xorg             SHMCTL                0 shmid: 0x1d000f, cmd: 2, buf: 0x7ffd1012f130
1243   Xorg              SHMDT                0 shmaddr: 0x7fe099426000
3209   llvmpipe-0        SHMDT                0 shmaddr: 0x7effebf5b000
3209   llvmpipe-0       SHMCTL ffffffffffffffea shmid: 0x1c8004, cmd: 0, buf: 0x0
3209   gnome-shell      SHMGET           1d8004 key: 0x0, size: 49152, shmflg: 0x3ff (IPC_CREAT|0777)
3209   gnome-shell       SHMAT     7effebf5b000 shmid: 0x1d8004, shmaddr: 0x0, shmflg: 0x0
3209   gnome-shell      SHMCTL                0 shmid: 0x1d8004, cmd: 0, buf: 0x0
1243   Xorg              SHMAT     7fe099426000 shmid: 0x1d8004, shmaddr: 0x0, shmflg: 0x0
1243   Xorg             SHMCTL                0 shmid: 0x1d8004, cmd: 2, buf: 0x7ffd1012f130
1243   Xorg              SHMDT                0 shmaddr: 0x7fe09941e000
3209   llvmpipe-0        SHMDT                0 shmaddr: 0x7effebf53000
3209   llvmpipe-0       SHMCTL ffffffffffffffea shmid: 0x1d000f, cmd: 0, buf: 0x0
3209   gnome-shell      SHMGET           1e000f key: 0x0, size: 131072, shmflg: 0x3ff (IPC_CREAT|0777)
3209   gnome-shell       SHMAT     7effebf3b000 shmid: 0x1e000f, shmaddr: 0x0, shmflg: 0x0
3209   gnome-shell      SHMCTL                0 shmid: 0x1e000f, cmd: 0, buf: 0x0
1243   Xorg              SHMAT     7fe099245000 shmid: 0x1e000f, shmaddr: 0x0, shmflg: 0x0
1243   Xorg             SHMCTL                0 shmid: 0x1e000f, cmd: 2, buf: 0x7ffd1012f130
1243   Xorg              SHMDT                0 shmaddr: 0x7fe099426000
3209   llvmpipe-0        SHMDT                0 shmaddr: 0x7effebf5b000
3209   llvmpipe-0       SHMCTL ffffffffffffffea shmid: 0x1d8004, cmd: 0, buf: 0x0
1243   Xorg              SHMDT                0 shmaddr: 0x7fe099245000
3209   llvmpipe-0        SHMDT                0 shmaddr: 0x7effebf3b000
3209   llvmpipe-0       SHMCTL ffffffffffffffea shmid: 0x1e000f, cmd: 0, buf: 0x0

例えば下のやつについて見てみる
1243 Xorg SHMAT 7fe099431000 shmid: 0x1b8004, shmaddr: 0x0, shmflg: 0x0

呼び出されているsyscallはshmatで、これのmanを読むと、
呼び出したプロセスのアドレス空間にshmidで指定されたSystem V共有メモリセグメントをアタッチする
今回でいうとshmaddrはnull(0x0)なので、使用されていないアドレスに対してアタッチ(0x1b8004)する
そしてそのアドレスを返す(7fe099431000)

drsnoop

direct reclaimイベントをトレースし、どのプロセスがdirect reclaimでページを割り当てているかを表示する

stessでメモリに負荷をかけて計測してみた

❯ sudo /usr/share/bcc/tools/drsnoop
COMM           PID     LAT(ms) PAGES
stress         29720      0.53   387
stress         29720      1.11   179
stress         29720      0.70   362
stress         29720      0.40    69
stress         29720      0.24    36
stress         29720      0.28   127
stress         29720      0.26    78
stress         29720      0.33   102
stress         29720      0.15    36
stress         29718      0.16   189
stress         29718      0.15   130
stress         29718      0.14   172
stress         29718      0.14   147
stress         29719      0.54   324
stress         29719      1.10   422
stress         29719      0.68   101
stress         29719      0.18   134
stress         29719      0.24   277
stress         29719      0.22    93
stress         29719      0.29    70
stress         29719      0.15   165
stress         29719      0.25   197
stress         29719      0.16    74