BPF Performance Toolsを読みながら学ぶ2

probeとかカーネルに関しての知識が浅すぎてとても難しい2章だった

目次

bitesize

ブロックデバイスのI/Oサイズをヒストグラムとして要約する
要求されたブロックサイズのI/O分布をプロセス名毎に表示する
block I/Oトレースポイントをトレースしてヒストグラムを更新する(カーネル空間側)
ユーザ空間側に非同期的にヒストグラムをコピーするのでオーバーヘッドがこくわずかで済む

前回と同様にddで書き込みながら試す

Kbytesはキロバイトの範囲
countはKbytesの範囲に入ったI/Oの数
distributionはcountの可視化

コマンドを実行したterminal

❯ dd if=/dev/zero of=./swapfile bs=1M count=2048
2048+0 records in
2048+0 records out
2147483648 bytes (2.1 GB, 2.0 GiB) copied, 3.24655 s, 661 MB/s
❯ sudo /usr/share/bcc/tools/bitesize 
Tracing block I/O... Hit Ctrl-C to end.
^C
Process Name = kworker/3:1H
     Kbytes              : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 3        |****************************************|

Process Name = ThreadPoolForeg
     Kbytes              : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 1        |****************************************|

Process Name = nautilus-deskto
     Kbytes              : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 1        |****************************************|

Process Name = kworker/u256:1
     Kbytes              : count     distribution
         0 -> 1          : 9        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 39       |*                                       |
         8 -> 15         : 9        |                                        |
        16 -> 31         : 5        |                                        |
        32 -> 63         : 5        |                                        |
        64 -> 127        : 2        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 1        |                                        |
       512 -> 1023       : 778      |*************************************** |
      1024 -> 2047       : 781      |****************************************|

Process Name = jbd2/sda1-8
     Kbytes              : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 4        |****************************************|
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 2        |********************                    |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 2        |********************                    |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 1        |**********                              |

bpftool perf list

システム内の全てのraw_tracepoint, tracepoint, kprobeを表示する

terminal 2

❯ sudo bpftrace -e 'tracepoint:syscalls:sys_enter_openat { printf("%s %s\n", comm, str(args->filename)); }'
terminal 1

❯ sudo bpftool perf list -p
[{
        "pid": 20499,
        "fd": 9,
        "prog_id": 19,
        "fd_type": "tracepoint",
        "tracepoint": "sys_enter_openat"
    }
]


❯ sudo bpftool prog show -p

[{
        "id": 19,
        "type": "tracepoint",
        "name": "sys_enter_opena",
        "tag": "1a6248388c2bcac4",
        "gpl_compatible": true,
        "loaded_at": 1570254902,
        "uid": 0,
        "bytes_xlated": 560,
        "jited": true,
        "bytes_jited": 371,
        "bytes_memlock": 4096,
        "map_ids": [18]
    }
]

vfsstat

一般的なVFS呼び出しをトレースし、一秒ごとの要約を出力する
ワークロードの特性評価、および時間経過に伴うオペレーションのパターンを見るのに役立つ
ユーザ空間側に非同期的にコピーするのでオーバーヘッドは小さい

READ/sはvfs_read()呼び出しの一秒あたりの平均数
WRITE/sはvfs_write()呼び出しの一秒あたりの平均数
CREATE/sはvfs_create()呼び出しの一秒あたりの平均数
OPEN/sはvfs_open()呼び出しの一秒あたりの平均数
FSYNC/sはvfs_fsync()呼び出しの一秒あたりの平均数

❯ sudo /usr/share/bcc/tools/vfsstat 
TIME         READ/s  WRITE/s CREATE/s   OPEN/s  FSYNC/s
10:32:21:        81       29        0        7        0
10:32:22:        70       30        0        5        0
10:32:23:       548      303        0     2045        0
10:32:24:        80      100        0        5        0
10:32:25:        30       29        0        6        0
10:32:26:        49       29        0       20        0
10:32:27:        29       28        0        5        0
10:32:28:      1000      339        0      526        0
10:32:29:        47       28        0       20        0
10:32:30:        29       28        0        5        0
^C

gethostlatency

getaddrinfo(),gethostbyname(),gethostbyname2()が呼び出されたときにトレースおよび出力する

PIDは呼び出しを実行しているプロセスのID
COMMは呼び出しを実行しているプロセス(コマンド)名
LATmsはlatency
HOSTはルックアップのターゲットであるホスト名

❯ sudo /usr/share/bcc/tools/gethostlatency 
TIME      PID    COMM                  LATms HOST
10:41:40  36378  DNS Resolver #1       19.90 detectportal.firefox.com
10:41:40  36387  DNS Resolver #2        0.84 detectportal.firefox.com
10:41:40  36378  DNS Resolver #1       16.87 mozilla.org
10:41:40  36388  DNS Resolver #3       19.86 mozilla.org
10:41:41  36387  DNS Resolver #2       34.27 push.services.mozilla.com
10:41:41  36378  DNS Resolver #1        0.57 push.services.mozilla.com
10:41:41  36388  DNS Resolver #3        0.69 push.services.mozilla.com
10:41:41  36387  DNS Resolver #2       33.96 tiles.services.mozilla.com
10:41:41  36388  DNS Resolver #3       19.09 content-signature-2.cdn.mozilla.net
10:41:41  36378  DNS Resolver #1       36.61 ocsp.digicert.com
^C

tcplife

TCPセッションをトレースして寿命(lifespan)を要約する
ワークロードの特性評価とフローアカウンティングに役立つ

PIDはプロセスID
COMMは呼び出しを実行しているプロセス(コマンド)名
LADDRはローカルIP
LPORTはローカルポート
RADDRはリモートIP
RPORTはリモートポート
TX_KBはトータルの送信(キロバイト)
RX_KBはトータルの受信(キロバイト)
MSはセッションの寿命

❯ sudo /usr/share/bcc/tools/tcplife 
PID   COMM       LADDR           LPORT RADDR           RPORT TX_KB RX_KB MS
41633 curl       192.168.221.129 36010 172.217.161.36  443       0    16 146.34
42828 curl       192.168.221.129 46722 182.22.59.229   443       0     5 67.13

USDT probe

node.jsのライブラリがあるので試してみる

terminal 1

~/workspace/usdt-example via ⬢ v10.15.3 took 11s 
❯ node index.js 
Firing probe...
Firing probe...
Firing probe...
Firing probe...
Firing probe...
Probe fired!
Firing probe...
Probe fired!
Firing probe...
Probe fired!
Firing probe...
Probe fired!
Firing probe...
Probe fired!
Firing probe...
Probe fired!
Firing probe...
Probe fired!
Firing probe...
Probe fired!
Firing probe...
Probe fired!
Firing probe...
Probe fired!
Firing probe...
Disable provider
Firing probe...
Disable provider
Firing probe...
Disable provider
^C
terminal 2

❯ sudo /usr/share/bcc/tools/trace -p $(pgrep node) 'u::firstProbe "%d - %s", arg1, arg2'
PID     TID     COMM            FUNC             -
58156   58156   node            firstProbe       9 - My little string
58156   58156   node            firstProbe       8 - My little string
58156   58156   node            firstProbe       7 - My little string
58156   58156   node            firstProbe       6 - My little string
58156   58156   node            firstProbe       5 - My little string
58156   58156   node            firstProbe       4 - My little string
58156   58156   node            firstProbe       3 - My little string
58156   58156   node            firstProbe       2 - My little string
58156   58156   node            firstProbe       1 - My little string
58156   58156   node            firstProbe       0 - My little string
^C