HackToTech

Hack To Technology

AWS Batchのexporterを書いてみた

久しぶりのブログ更新
ここ最近読書によるインプット過多で全然アウトプットしていないので久しぶりにまともなものを書く

golangの勉強がてら書いてみたので見る人が見たら酷いかもしれない
シンプルにそれぞれのStateのJobをメトリクスとして取得してみた
Queue毎にカウントしただけのメトリクスを吐き出すことも考えたけど、PromQLで計算すれば出来るから一旦はこのままにしてみた
github.com

コード書いたついでに久しぶりにGrafanaも周りも触ったらかなり改善されていい感じだったので、仕事でもGrafana使いたい欲がすごい(今はDatadogを主に使ってる)
↓はサクっと作ったAWS BatchのGrafanaのダッシュボード

f:id:atr0phy:20200714005748p:plain
AWS Batch ダッシュボード
↓のjsonをそのままimportすれば同様のダッシュボードが見れる

特定のIAMロールで実行できるSystemsManagerのドキュメントを制限する方法

特定のIAMロールで実行できるSystemsManagerのドキュメントを制限する方法

今後もまた実装したくなることがありそうなので、残しとく
結論から言うと大体下のようなIAM Policyで制限をかけることが可能

{
    "Version": "2012-10-17",
    "Statement": [
        {
            "Effect": "Allow",
            "Action": "ssm:StartSession",
            "Resource": [
                "arn:aws:ec2:*:*:instance/*"
            ],
            "Condition": {
                "BoolIfExists": {
                    "ssm:SessionDocumentAccessCheck": "true"
                },
                "StringLike": {
                    "ssm:resourceTag/Name": "FugaFuga"
                }
            }
        },
        {
            "Effect": "Allow",
            "Action": "ssm:StartSession",
            "Resource": "arn:aws:ssm:*:*:document/HogeHogeDocument"
        },
        {
            "Effect": "Allow",
            "Action": [
                "ssm:TerminateSession",
                "ssm:ResumeSession"
            ],
            "Resource": "arn:aws:ssm:*:*:session/${aws:username}-*"
        }
    ]
}

やっている内容について書いていく

まずはこのstatement

{
    "Effect": "Allow",
    "Action": "ssm:StartSession",
    "Resource": [
        "arn:aws:ec2:*:*:instance/*"
    ],
    "Condition": {
        "BoolIfExists": {
            "ssm:SessionDocumentAccessCheck": "true"
        },
        "StringLike": {
            "ssm:resourceTag/Name": "FugaFuga"
        }
    }
}

単純にActionとResourceはSSMのStartSessionをどのEC2インスタンスに対してでも実行できるようにしている
その上でConditionを使用して対象の絞り込みをかける
BoolIfExistsのssm:SessionDocumentAccessCheckは下の公式を読むとよくわかるが、
AWS CLI でセッションドキュメントのアクセス許可チェックを適用する
通常ssm:StartSessionを許可した場合にSSM-SessionManagerRunShellがデフォルトで許可される
これが許可されてしまうとインスタンスに接続してごにょごにょ何でも出来てしまうのでまず明示的に許可していないドキュメントへのアクセスを遮断する為に必要
次にStringLikeで ssm:resourceTag/Name を絞っているが、これは特定の名前のインスタンスにのみ実行を許可するために使っている(今回であればNameがFugaFugaのインスタンスだけとなる)
これもよくある、この種類のインスタンスに対しては良いけど他へは実行できて欲しくないといったときに重宝する

次にこのstatement

{
    "Effect": "Allow",
    "Action": "ssm:StartSession",
    "Resource": "arn:aws:ssm:*:*:document/HogeHogeDocument"
}

前のstatementで明示的に許可をしていないドキュメントについてはアクセス出来なくさせたので、
ドキュメントを指定することによって実行を許可している
なんで前のstatementと分けて書いているかというと、
前のstatementはConditionのStringLikeでTagの一致を条件として使用しているので、ドキュメントにも同様のTagがないと弾かれてしまうようになる(ドキュメントのName tagにFugaFugaを設定するつもりはないので、今回は分けている)

最後にこのstatement

{
    "Effect": "Allow",
    "Action": [
        "ssm:TerminateSession",
        "ssm:ResumeSession"
    ],
    "Resource": "arn:aws:ssm:*:*:session/${aws:username}-*"
}

自分自身がStartSessionで作成したsessionに対してResumeとTerminateを出来るように許可している

書いてみると意外と単純だが、Conditionを扱うのが久しぶりだと若干頭を悩ませる

IAMで特定のロールからのみAsuume Roleをさせる方法

IAMで特定のロールからのみAsuume Roleをさせる方法

Assume元を再作成した場合にも出来るようにしたくて試行錯誤したついでにメモを残す

Principalを使用する方法

公式にも書いてある方法
基本的に一番よく使うのはこれだと思う

{
  "Version": "2012-10-17",
  "Statement": {
    "Effect": "Allow",
    // 対象のアカウント及びロール
    "Principal": { "AWS": "arn:aws:iam::123456789012:root" },
    "Action": "sts:AssumeRole",
    "Condition": { "Bool": { "aws:MultiFactorAuthPresent": "true" } }
  }
}

ただこれを使った場合

"Principal": { "AWS": "arn:aws:iam::123456789012:root" },

ここでUserやRoleを指定することになるが、これは保存時に自動的にPrincipalIDに変更される(ドキュメントにも書いてあるが)

Principal 要素に特定の IAM ロールまたはユーザーの ARN が含まれている場合、この ARN はポリシーの保存時に一意のプリンシパル ID に変換されます。 これにより、第三者がロールやユーザーを削除して再作成することで、そのユーザーのアクセス許可をエスカレートするリスクを緩和できます。 したがって、信頼ポリシーの Principal 要素で指し示しているユーザーまたはロールを削除し、再作成する場合、ロールを編集して ARN を置き換える必要があります。

ので、再作成したりしない or 再作成してもPrincipalを更新するので問題がない場合はこれでOK
ただ再作成してもAssumeできるようにしたいなら次のように実装しないとできなかった

Principal + Conditionを使用する方法

さっきと同様にPrincipalでまずアカウントを絞り込む
その上で、元となるロールをConditionのArnEqualsで更に絞り込む
こうすることによってそのアカウントのロールが再作成されてもAssumeできる

{
  "Version": "2012-10-17",
  "Statement": [
    {
      "Effect": "Allow",
      "Principal": {
        // 対象のアカウント
        "AWS": "arn:aws:iam::123456789012:root"
      },
      "Action": "sts:AssumeRole",
      "Condition": {
        "ArnEquals": {
          // 対象のアカウントのロール
          "aws:PrincipalArn": "arn:aws:iam::123456789012:role/assume-from"
        }
      }
    }
  ]
}

BPF本を読みながら学ぶ10

BPF本を読みながら学ぶ10

10章、ネットワークについて
割と知らない単語があって調べるのに苦労した
後半はbpftraceを用いたツールの説明が多い

目次

用語

  • Queueing Discipline(キューイングの規則)
    • 入力側 (ingress: 入口)、出力側 (egress: 出口) いずれかの デバイスのキューを管理するアルゴリズムのこと。

  • AQM(Active Queue Management)
    • CoDel(Controlled Delay)
    • RED(Random Early Detection)
  • XDP(eXpress Data Path)
    • NICドライバー内でのeBPFによるフックを介したパケット処理
    • 柔軟で処理速度が優秀(ACMの動画を見るにDDoS攻撃とかに対しても有用っぽい(BPF本側でも言及されてた))
    • 無駄なコンテキストスイッチが走らない(カーネル空間側で処理する)
  • TCP輻輳制御
    • Cubic(default)
    • Reno
    • Tahoe
    • DCTCP
    • BBR

参考

ネットワークのパフォーマンス分析

  1. ネットワークの統計情報を確認する
    パケットレート/スループット、およびTCP接続がある場合はTCPの接続/再送信のレート
    ss / nstat / netstat / sar
  2. TCP接続の特徴を観測し、非効率部分を探す
    tcplife
  3. ネットワークインタフェースのスループット制限に達しているかを確認する
    sar / nicstat
  4. TCPの再送信やドロップなどの異常なTCPイベントをトレースする
    tcpretrans / tcpdrop / skb:kfree_skb tracepoint
  5. DNSの名前解決の遅延を測定する
    gethostlatency
  6. コネクションの遅延、TTFBの遅延、スタックの遅延など様々な箇所からネットワークの遅延状況を測定する
  7. bufferbloatなど負荷によって遅延時間を大きく変化するので注意すること
  8. 負荷生成ツールでホスト間のネットワークスループットを調べて既知のワークロードに対するネットワークイベントを調べる
    iperf / netperf
  9. bpftoolを使用する
  10. カーネルのスタックトレースのCPUプロファイリングを使用して、プロトコルおよびドライバーの処理に費やされるCPU時間を定量化する
  11. トレースポイントとkprobes

ss

ソケットの統計をダンプする
netstatと同様の情報を表示できる

フィールド1

Netid 接続の種類
u_str: TCP
u_dgr: UDP
v_str: vSocket
State ESTAB: Established
UNCONN: Close
Recv-Q ソケットからプロセスへまだ渡されていないデータのバイト数
Send-Q プロセスから渡されたがまだ送信されていないデータのバイト数
Local Address:Port ローカルのホスト or IPアドレス + Port
Peer Address:Port リモートのホスト or IPアドレス + Port
❯ ss | head -n10
Netid   State   Recv-Q   Send-Q                 Local Address:Port   Peer Address:Port
u_str   ESTAB   0         0                                 * 47233              * 47234
u_str   ESTAB   0         0                                 * 45092              * 44080
u_str   ESTAB   0         0                                 * 44587              * 44588
u_str   ESTAB   0         0       /run/systemd/journal/stdout 43268              * 42713
u_str   ESTAB   0         0                                 * 43077              * 44112
u_str   ESTAB   0         0   /var/run/dbus/system_bus_socket 42983              * 44430
u_str   ESTAB   0         0                                 * 53695              * 48964
u_str   ESTAB   0         0                /run/user/1000/bus 45967              * 46626
u_str   ESTAB   0         0                                 * 44351              * 44352
u_str   ESTAB   0         0                                 * 230142             * 230141
u_str   ESTAB   0         0                                 * 44138              * 44139
u_str   ESTAB   0         0                                 * 42390              * 45199
u_str   ESTAB   0         0   /run/containerd/containerd.sock 33779              * 34376
u_str   ESTAB   0         0                                 * 30251              * 30252
icmp6   UNCONN  0         0                                 *:ipv6-icmp          *:*
tcp     ESTAB   0         0                                 192.168.221.129:49716 192.30.253.124:https
tcp     ESTAB   0         0                                 192.168.221.129:40098 35.161.236.240:https
v_str   ESTAB   0         0                                 1081845576:1023 0:976
v_str   ESTAB   0         0                                 1081845576:3128913646 0:976

フィールド2

users プロセス名
プロセスID
ファイルディスクリプタ
timer タイマー名
タイマーの有効期限
再送の発生回数
uid ソケットの属するユーザーID
ino VFSのソケットのinodeの番号
sk ソケットのUUID
skmem r?: パケットを受信するために割り当てられたメモリ
rb?: パケットの受信に割り当てることができる合計のメモリ
t?: パケットを送信するのに使用しているメモリ(レイヤー3へ送信済み)
tb?: パケットの送信に割り当てることができる合計のメモリ
f?: ソケットによってキャッシュとして割り当てられたが、パケットの送受信にはまだ使われていないメモリ
(パケットの送受信にメモリが必要な場合、追加のメモリを割り当てる前にこのキャッシュ内のメモリが使用される)
w?: パケットの送信に割り当てられたメモリ(レイヤー3へ未送信)
o?: ソケットオプションの保存に使用されるメモリ(例えばTCP MD5署名のkey)
bl?: skバックログキューに使用されるメモリ
(プロセスのコンテキストでは、プロセスがパケットを受信しているところで、新たにパケットを受信した際にskバックログキューに入れられ、プロセスは即座に受信することができる)
d?: 生のUDPのドロップカウンターっぽい?
おそらく、この辺この辺
cubic 輻輳のアルゴリズム名が表示される(デフォルトなのでcubic)
rto TCPの再送信タイムアウト値(ミリ秒)
rtt 平均ラウンドトリップタイム(ミリ秒)/ラウンドトリップタイムの平均偏差(ミリ秒)
ato ACKのタイムアウト(ミリ秒)、遅延ACKモードで使用する
mss 最大セグメントサイズ
pmtu パスのMTU値
rcvmss ピアに知らせる最大セグメントサイズ(MTU - 40(TCPヘッダとIPヘッダ分) bytes)
advmss Advertised MSS(適切な和訳がわからなかった)
cwnd 輻輳ウィンドウサイズ
bytes_acked 正常に送信されたバイト数
bytes_received 受信したバイト数
segs_out 送信されたセグメント数
segs_in 受信したセグメント数
data_segs_out RFC4898 tcpEStatsDataSegsOut(tcpi_data_segs_out)
send egressのbps
lastsnd 最後のパケットが送信されてからの時間(ミリ秒)
lastrcv 最後にパケットを受信してからの時間(ミリ秒)
lastack 最後にACKを受信してからの時間(ミリ秒)
pacing_rate ペーシングのレート(bps)/最大ペーシングのレート(bps)
delivery_rate tcp_rate_gen()で測定された最新のgoodput(詳細)値
app_limited ソケットのスループットが送信アプリケーションによって制限されたときにgoodputが測定されたかどうかを示すbool値
busy データを送信中の時間(ミリ秒)
rcv_space 受信バッファのソケットオートチューニングをするヘルパー変数
rcv_ssthresh 受信のスロースタートサイズの閾値(現在のウィンドウクランプ)
minrtt 最小ラウンドトリップタイム
❯ ss -tiepm
State Recv-Q   Send-Q   Local Address:Port    Peer Address:Port
ESTAB 0        0      192.168.221.129:49716 192.30.253.124:https
users:(("firefox",pid=4300,fd=44)) timer:(keepalive,71582min,0) uid:1000 ino:233806 sk:2d4 <->
     skmem:(r0,rb131072,t0,tb87040,f0,w0,o0,bl0,d0) cubic rto:300 rtt:28.715/50.18 ato:40 mss:1460 pmtu:1500 rcvmss:1460 advmss:1460 cwnd:10 bytes_acked:1631 bytes_received:4091 segs_out:20 segs_in:31 data_segs_out:14 data_segs_in:16 send 4.1Mbps lastsnd:17864 lastrcv:17864 lastack:17864 pacing_rate 8.1Mbps delivery_rate 132.7Mbps app_limited rcv_space:14600 rcv_ssthresh:64076 minrtt:0.235
ESTAB  0        0     192.168.221.129:40098 35.161.236.240:https
users:(("firefox",pid=4300,fd=70)) timer:(keepalive,5min42sec,0) uid:1000 ino:88797 sk:2d1 <->
     skmem:(r0,rb131072,t0,tb87040,f0,w0,o0,bl0,d0) cubic rto:204 rtt:0.227/0.044 ato:40 mss:1460 pmtu:1500 rcvmss:1460 advmss:1460 cwnd:10 bytes_acked:10911 bytes_received:12344 segs_out:359 segs_in:552 data_segs_out:274 data_segs_in:277 send 514.5Mbps lastsnd:257984 lastrcv:257984 lastack:257984 pacing_rate 1027.4Mbps delivery_rate 108.1Mbps app_limited busy:80ms rcv_space:14600 rcv_ssthresh:64076 minrtt:0.223

参考

ip

ルーティング、ネットワークデバイス、インターフェイス、トンネルの表示/操作

フィールド

interface name インターフェイス名(lo, ens33)
interface flag UP: インターフェイスが有効である状態
LOWER_UP: イーサネットケーブルが差し込まれ、デバイスがネットワークに接続されている
LOOPBACK: インターフェイスは他のホストと通信を行わない(バウンスされたパケットのみを受信可能)
BROADCAST: 同じリンクを共有するすべてのホストにパケットを送信する機能がある(例: イーサネットリンク)
MULTICAST: マルチキャスト機能が有効
mtu Maximum Transmission Unit
qdisc インターフェイスキューイングアルゴリズム
noqueue: キューに入れない
fq_codel: 詳細
state 状態
mode おそらくLINKモード
DEFAULT or DORMANT
group デバイスグループ(/etc/iproute2/groupに載っているものが指定できる)
qlen デバイスのデフォルトの送信キューの長さ
link リンク(loopback, ethernet)
brd ブロードキャストアドレス
RX bytes: 受信したバイト数の合計
packets: 受信したパケット数の合計
errors: 受信したエラーパケット数の合計
dropped: 受信した際にバッファに空きがなかったりしてドロップしたパケット数の合計
overrun: 受信リングバッファのオーバーフローの合計
mcast: 受信したマルチキャストの合計
TX bytes: 送信したバイト数の合計
packets: 送信したパケット数の合計
errors: 送信した問題のあるパケット数の合計
dropped: 送信したパケットのドロップした回数(レアらしい)
carrier: シグナルの変調に問題があった数の合計(デュプレックスミスマッチとか物理ケーブル/コネクタの問題とか)
collsns: 衝突(コリジョン)した回数
❯ ip -s link
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    RX: bytes  packets  errors  dropped overrun mcast   
    696562     8158     0       0       0       0       
    TX: bytes  packets  errors  dropped carrier collsns 
    696562     8158     0       0       0       0       
2: ens33: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP mode DEFAULT group default qlen 1000
    link/ether 00:0c:29:7b:a7:48 brd ff:ff:ff:ff:ff:ff
    RX: bytes  packets  errors  dropped overrun mcast   
    65473200   82427    0       0       0       0       
    TX: bytes  packets  errors  dropped carrier collsns 
    7752597    46923    0       0       0       0       
❯ ip route
default via 192.168.221.2 dev ens33 proto dhcp metric 100 
169.254.0.0/16 dev ens33 scope link metric 1000 
192.168.221.0/24 dev ens33 proto kernel scope link src 192.168.221.129 metric 100 

参考

nstat

カーネルのSNMPカウンターとネットワークインターフェースの統計を確認するシンプルなツール

統計情報の確認

❯ nstat -s
#kernel
IpInReceives                    37402              0.0
IpInAddrErrors                  3                  0.0
# 省略

参考

netstat

ネットワーク接続、経路テーブル、インターフェースの状態、マスカレード接続、 netlink メッセージ、マルチキャストのメンバーシップを表示する

フィールド

Proto ソケットのプロトコル
RefCnt 参照カウント(このソケットに接続されているプロセスの数)
Flags ACC: SO_ACCEPTON(ソケットが接続されておらず、かつそれを用いるプログラムが接続要求を待っている場合に用いられる)
W: SO_WAITDATA
N: SO_NOSPACE
Type ソケットのアクセスタイプ
SOCK_DGRAM: データグラム(connectionsless)モードのソケット
SOCK_STREAM: ストリーム(connection)ソケット
SOCK_RAW: RAWソケット
SOCK_RDM: 信頼性の高いメッセージを届けるソケット
SOCK_SEQPACKET: シーケンシャルパケットのソケット
SOCK_PACKET: RAWインターフェースアクセスのソケット
UNKNOWN: 不明
State FREE: ソケットは割り当てられていない
LISTENING: ソケットは接続要求の待ち状態
CONNECTING: ソケットは接続中の状態
CONNECTED: ソケットは接続状態
DISCONNECTING: ソケットは切断中の状態
空欄: ソケットは他のソケットに接続されていない
UNKNOWN: 基本的に現れない
I-Node inodeの番号
PID/Program name このソケットをオープンしているプロセスID/プロセス名
Path ソケットに結び付けられているプロセスのパス
❯ netstat -anp
稼働中のインターネット接続 (サーバと確立)
Proto 受信-Q 送信-Q 内部アドレス            外部アドレス            状態       PID/Program name    
tcp        0      0 192.168.122.1:53        0.0.0.0:*               LISTEN      -                   
tcp        0      0 127.0.0.53:53           0.0.0.0:*               LISTEN      -                   
tcp        0      0 127.0.0.1:631           0.0.0.0:*               LISTEN      -                   
tcp        0      0 192.168.221.129:42142   13.35.67.43:443         ESTABLISHED 8601/firefox        
tcp        0      0 192.168.221.129:42340   99.84.55.56:443         TIME_WAIT   -                   
tcp        0      0 192.168.221.129:53566   172.217.25.206:443      ESTABLISHED 8601/firefox        
tcp        0      0 192.168.221.129:45744   107.178.248.96:443      ESTABLISHED 8601/firefox        
tcp        0      0 192.168.221.129:47086   104.107.111.107:443     ESTABLISHED 8601/firefox
# 省略
稼働中のUNIXドメインソケット (サーバと確立)
Proto RefCnt Flags       Type       State         I-Node   PID/Program name     パス
unix  2      [ ]         DGRAM                    31499    -                    /var/spool/postfix/dev/log
unix  2      [ ACC ]     STREAM     LISTENING     41813    2880/gnome-session-  @/tmp/.ICE-unix/2880
unix  2      [ ]         DGRAM                    43395    2859/systemd         /run/user/1000/systemd/notify
unix  2      [ ACC ]     SEQPACKET  LISTENING     25863    -                    /run/udev/control
unix  2      [ ACC ]     STREAM     LISTENING     43398    2859/systemd         /run/user/1000/systemd/private
unix  2      [ ACC ]     STREAM     LISTENING     43402    2859/systemd         /run/user/1000/gnupg/S.gpg-agent.ssh
unix  2      [ ACC ]     STREAM     LISTENING     43403    2859/systemd         /run/user/1000/gnupg/S.dirmngr
unix  2      [ ACC ]     STREAM     LISTENING     43404    2859/systemd         /run/user/1000/gnupg/S.gpg-agent.browser
unix  2      [ ACC ]     STREAM     LISTENING     43405    2859/systemd         /run/user/1000/snapd-session-agent.socket
❯ netstat -s
Ip:
    Forwarding: 1
    15127 total packets received
    3 with invalid addresses
    0 forwarded
    0 incoming packets discarded
    15122 incoming packets delivered
    14728 requests sent out
Icmp:
    1 ICMP messages received
    0 input ICMP message failed
    ICMP入力ヒストグラム:
        echo requests: 1
    4 ICMP messages sent
    0 ICMP messages failed
    ICMP出力ヒストグラム:
        destination unreachable: 3
        echo replies: 1
IcmpMsg:
        InType8: 1
        OutType0: 1
        OutType3: 3
Tcp:
    53 active connection openings
    0 passive connection openings
    2 failed connection attempts
    3 connection resets received
    0 connections established
    14109 segments received
    13845 segments sent out
    3 segments retransmitted
    0 bad segments received
    15 resets sent
Udp:
    954 packets received
    3 packets to unknown port received
    0 packet receive errors
    872 packets sent
    0 receive buffer errors
    0 send buffer errors
    IgnoredMulti: 57

参考

nicstat

パケット、キロバイト/秒、平均パケットサイズなど、すべてのNICのネットワーク統計を出力する

フィールド

Time 時間(HH:MM:SS)
Int インターフェイス名
rKB/s キロバイト/秒の読み取り(受信)
wKB/s キロバイト/秒の書き込み(送信)
rPk/s パケット(TCP Segments, UDP Datagrams)/秒の読み取り(受信)
wPk/s パケット(TCP Segments, UDP Datagrams)/秒の書き込み(送信)
rAvs 読み取りのパケットの平均サイズ(受信)
wAvs 書き込みのパケットの平均サイズ(送信)
%Util インターフェイスの使用率
Sat 飽和(Saturation)/インターフェイスのエラー/秒の数
❯ nicstat
    Time      Int   rKB/s   wKB/s   rPk/s   wPk/s    rAvs    wAvs %Util    Sat
01:02:50    ens33   27.27    0.31   19.31    4.04  1446.1   78.08  0.02   0.00
01:02:50       lo    0.02    0.02    0.19    0.19   87.71   87.71  0.00   0.00

ethtool

ネットワークドライバーとハードウェア設定のクエリもしくはコントロール

-Sでデバイスの統計情報の確認

❯ ethtool -S ens33
NIC statistics:
     rx_packets: 82901
     tx_packets: 17923
     rx_bytes: 119175472
     tx_bytes: 1435399
     rx_broadcast: 0
     tx_broadcast: 0
     rx_multicast: 0
     tx_multicast: 0
     rx_errors: 0
     tx_errors: 0
     tx_dropped: 0
     multicast: 0
     collisions: 0
     rx_length_errors: 0
     rx_over_errors: 0
     rx_crc_errors: 0
     rx_frame_errors: 0
     rx_no_buffer_count: 0
     rx_missed_errors: 0
     tx_aborted_errors: 0
     tx_carrier_errors: 0
     tx_fifo_errors: 0
     tx_heartbeat_errors: 0
     tx_window_errors: 0
     tx_abort_late_coll: 0
     tx_deferred_ok: 0
     tx_single_coll_ok: 0
     tx_multi_coll_ok: 0
     tx_timeout_count: 0
     tx_restart_queue: 0
     rx_long_length_errors: 0
     rx_short_length_errors: 0
     rx_align_errors: 0
     tx_tcp_seg_good: 15
     tx_tcp_seg_failed: 0
     rx_flow_control_xon: 0
     rx_flow_control_xoff: 0
     tx_flow_control_xon: 0
     tx_flow_control_xoff: 0
     rx_long_byte_count: 119175472
     rx_csum_offload_good: 82844
     rx_csum_offload_errors: 0
     alloc_rx_buff_failed: 0
     tx_smbus: 0
     rx_smbus: 0
     dropped_smbus: 0

-iでドライバーの詳細の表示

❯ ethtool -i ens33
driver: e1000
version: 7.3.21-k8-NAPI
firmware-version: 
expansion-rom-version: 
bus-info: 0000:02:01.0
supports-statistics: yes
supports-test: yes
supports-eeprom-access: yes
supports-register-dump: yes
supports-priv-flags: no

BPF本を読みながら学ぶ9

9章、 ディスクI/Oについて

目次

blkparse

Trace Actions 説明
C Complete 以前に発行したリクエストが完了した
D Issued ブロックレイヤーのキューまたはI/Oスケジューラに存在していたリクエストがドライバへ発行された
I Inserted 内部キューへの追加とドライバによる後のサービスのためにI/Oスケジューラにリクエストを送信した
Q Queued I/Oをキューに入れようとしている
実際のリクエストはまだ存在しない
B Bounced データページがハードウェアから到達できないため、より低いメモリロケーションへバウンスする必要がある
これにより、データをカーネルバッファとの間でコピーする必要がある為、I/Oパフォーマンスが大幅に低下する
M Back merge I/Oの開始から終了までの間に以前にインサートされたリクエストが存在する為、I/Oスケジューラはそれらをマージできる
要するに順番通りにくっつけて処理する感じ
F Front merge バックマージと同じ
以前にインサートされたリクエストが開始されるところで、このI/Oが終了する点を除く
要するに順番を入れ替えてくっつけて処理する感じ
M Front or Back merge そのまま
G Get request 任意のタイプのリクエストをブロックデバイスに送信するには、初めに構造体のリクエストコンテナを割り当てる必要がある
S Sleep 利用可能なリクエストの構造体がなかった為、発行者はリクエストの構造体が解放されるのを待つ必要がある
P Plug 空のブロックデバイスキューにI/Oがキューイングされる前に、Linuxはデータが必要になって将来的にキューにI/Oが追加されることを予想してキューにプラグを差し込む
U Unplug デバイスにいくつかのリクエストデータがキューイングされていて、ドライバへリクエストの送信を開始する
タイムアウトの期間を経過した場合、もしくは多くのリクエストがキューに追加された際に自動的に発生する場合がある
T Unplug due to timer キューにプラグを差し込んだあとに、I/Oを要求するリクエストがない場合、Linuxは定義された期間が経過した後、自動的にプラグを取り外す
X Split RAIDもしくはデバイスマッパーの仕組みでは、インカミングI/Oがデバイスもしくは内部ゾーンにまたがるケースがあり、サービスのために細かく分割するひつようがある
RAID/デバイスマッパーの仕組みが不適切であるために、パフォーマンスの問題が発生していることを示す場合もあるが、通常の境界条件の一部にすぎない場合もある
A Remap スタックされたデバイスの場合、インカミングI/Oは、I/Oスタックでリマップされる
リマップアクションは、何が何にリマップされているかを詳細に示す

参考

rwbs

R Read
W Write
M Meta-data
S Synchronous
A Read-Ahead
F Flush or Force Unit Access
D Discard
E Erase
N No data

参考

I/Oスケジューラ

  • クラシックスケジューラ
    • Noop
      • スケジューリングを行わない(要するにリクエスト順に処理する)
    • Deadline
      • レイテンシのデッドライン(ミリ秒単位で指定)を強制しようとする(リアルタイムシステムで望ましい)
      • レイテンシの外れ値が防げる(スタベーション)
    • CFQ
      • CPUのスケジューリングと同様にI/Oタイムスライスを割り当てる
  • マルチキュースケジューラ
    • BFQ
      • 遅いI/Oデバイスでも良好なレスポンスを返せる
      • 遅いCPUもしくは、高スループットのデバイスには不向き
      • でかいアプリケーションをロードするときに有用
    • kyber
      • 高速なマルチキューデバイスように設計されている
      • 2つのリクエストキューが存在する
        • 同期リクエストキュー
        • 非同期リクエストキュー
    • none
      • スケジューリングを行わない
      • NVMEとかの高速ランダムI/Oデバイスに向いている
    • mq-deadline
      • マルチキューデバイス向けのデッドラインI/Oスケジューラ
      • CPUオーバーヘッドがかなり低いため、オールラウンダー

ディスクI/Oのパフォーマンス分析

  1. ディスクのパフォーマンス分析から始める
  2. 基本的なディスクメトリクスを確認する(リクエストタイム, IOS, Utilization)
  3. 正常な状態がわからない場合はfioとかで計測する
  4. I/Oのレイテンシの分布を確認し、マルチモーダル分析と外れ値を確認する
    biolatency
  5. 個々のI/Oをトレースし、パターンを探る
    biosnoop
  6. bpftraceを使用する

blktrace

ブロックデバイスのライブトレースを実行する

フィールド

デバイスのメジャー,マイナーバージョン
CPU ID
シーケンス番号
タイムスタンプ(秒)
プロセスID
トレースアクション(ID) blkparse
RWBS rwbs
アドレス/サイズ[デバイス]
❯ sudo btrace /dev/sda1
  8,0    1        1     0.000000000 14725  A  WS 15475728 + 8 <- (8,1) 15473680
  8,1    1        2     0.000000479 14725  Q  WS 15475728 + 8 [ThreadPoolForeg]
  8,1    1        3     0.000006639 14725  G  WS 15475728 + 8 [ThreadPoolForeg]
  8,1    1        4     0.000007478 14725  P   N [ThreadPoolForeg]
  8,1    1        5     0.000008846 14725  U   N [ThreadPoolForeg] 1
  8,1    1        6     0.000009364 14725  I  WS 15475728 + 8 [ThreadPoolForeg]
  8,1    1        7     0.000026680 14725  D  WS 15475728 + 8 [ThreadPoolForeg]
  8,1    1        8     0.000198604  4914  C  WS 15475728 + 8 [0]
  8,0    1        9     0.000237768   422  A  WS 17113736 + 8 <- (8,1) 17111688
  8,1    1       10     0.000238263   422  Q  WS 17113736 + 8 [jbd2/sda1-8]
  8,1    1       11     0.000240262   422  G  WS 17113736 + 8 [jbd2/sda1-8]
  8,1    1       12     0.000240623   422  P   N [jbd2/sda1-8]
  8,0    1       13     0.000240940   422  A  WS 17113744 + 8 <- (8,1) 17111696
  8,1    1       14     0.000241052   422  Q  WS 17113744 + 8 [jbd2/sda1-8]
  # 省略
  8,1    1       79     0.000250469   422  U   N [jbd2/sda1-8] 1
  8,1    1       80     0.000250716   422  I  WS 17113736 + 184 [jbd2/sda1-8]
  8,1    1       81     0.000252183   422  D  WS 17113736 + 184 [jbd2/sda1-8]
  8,1    1       82     0.000475940  4914  C  WS 17113736 + 184 [0]
  8,0    1       83     0.000501828   422  A FWFS 17113920 + 8 <- (8,1) 17111872
  8,1    1       84     0.000502301   422  Q  WS 17113920 + 8 [jbd2/sda1-8]
  8,1    1       85     0.000503486   422  G  WS 17113920 + 8 [jbd2/sda1-8]
  8,1    1       86     0.000504014   422  I  WS 17113920 + 8 [jbd2/sda1-8]
  8,1    1       87     0.000510367   370  D  WS 17113920 + 8 [kworker/1:1H]
  8,1    1       88     0.000614921  4914  C  WS 17113920 + 8 [0]
  8,0    1       89     0.196179477 14725  A  WS 411398904 + 8 <- (8,1) 411396856
  8,1    1       90     0.196180172 14725  Q  WS 411398904 + 8 [ThreadPoolForeg]
  8,1    1       91     0.196184976 14725  G  WS 411398904 + 8 [ThreadPoolForeg]
  8,0    3        1     0.615787407 15059  A  WS 15475728 + 8 <- (8,1) 15473680
  8,1    3        2     0.615788204 15059  Q  WS 15475728 + 8 [ThreadPoolForeg]
  8,1    3        3     0.615792400 15059  G  WS 15475728 + 8 [ThreadPoolForeg]
  8,1    3        4     0.615793068 15059  P   N [ThreadPoolForeg]
  8,0    3        5     0.615809324 15059  A  WS 15475736 + 8 <- (8,1) 15473688
  8,1    3        6     0.615809496 15059  Q  WS 15475736 + 8 [ThreadPoolForeg]
  8,1    3        7     0.615810115 15059  M  WS 15475736 + 8 [ThreadPoolForeg]
  8,1    3        8     0.615811006 15059  U   N [ThreadPoolForeg] 1
  8,1    3        9     0.615811499 15059  I  WS 15475728 + 16 [ThreadPoolForeg]
  8,1    3       10     0.615815352 15059  D  WS 15475728 + 16 [ThreadPoolForeg]
  8,1    3       11     0.616105591     0  C  WS 15475728 + 16 [0]
CPU1 (8,1):
 Reads Queued:           0,        0KiB     Writes Queued:          61,      252KiB
 Read Dispatches:        0,        0KiB     Write Dispatches:       14,      252KiB
 Reads Requeued:         0      Writes Requeued:         0
 Reads Completed:        0,        0KiB     Writes Completed:       14,      252KiB
 Read Merges:            0,        0KiB     Write Merges:           47,      188KiB
 Read depth:             0          Write depth:             2
 IO unplugs:             9          Timer unplugs:           0
CPU3 (8,1):
 Reads Queued:           0,        0KiB     Writes Queued:           2,        8KiB
 Read Dispatches:        0,        0KiB     Write Dispatches:        1,        8KiB
 Reads Requeued:         0      Writes Requeued:         0
 Reads Completed:        0,        0KiB     Writes Completed:        1,        8KiB
 Read Merges:            0,        0KiB     Write Merges:            1,        4KiB
 Read depth:             0          Write depth:             2
 IO unplugs:             1          Timer unplugs:           0

Total (8,1):
 Reads Queued:           0,        0KiB     Writes Queued:          63,      260KiB
 Read Dispatches:        0,        0KiB     Write Dispatches:       15,      260KiB
 Reads Requeued:         0      Writes Requeued:         0
 Reads Completed:        0,        0KiB     Writes Completed:       15,      260KiB
 Read Merges:            0,        0KiB     Write Merges:           48,      192KiB
 IO unplugs:            10          Timer unplugs:           0

Throughput (R/W): 0KiB/s / 337KiB/s
Events (8,1): 254 entries
Skips: 0 forward (0 -   0.0%)

biotop

プロセスtopによるブロックデバイス(ディスク)I/O
topのディスクI/O版

フィールド

loadavg /proc/loadavg
PID キャッシュされたプロセスID(存在する場合は)
基本的にはI/Oの原因となるプロセスを特定する(保証はされない)
COMM キャッシュされたプロセス名(存在する場合は)
基本的にはI/Oの原因となるプロセスを特定する(保証はされない)
D 方向(Direction)
R(Read)
W(Write)
MAJ メジャーデバイス番号
MIN マイナーデバイス番号
DISK ディスクデバイス名
I/O インターバル間のI/Oの数
Kbytes インターバル間のI/OのKbytesの合計
AVGms デバイスに発行されてから完了するまでのI/Oレイテンシの平均時間(ミリ秒)
16:50:00 loadavg: 0.14 0.04 0.01 1/756 30610

PID    COMM             D MAJ MIN DISK       I/O  Kbytes  AVGms
422    jbd2/sda1-8      W 8   0   sda          2     132   0.26
28892  kworker/u256:2   W 8   0   sda         11      44   0.32
30344  cp               W 8   0   sda          1       4   0.23
30345  cp               W 8   0   sda          1       4   0.17
30286  cat              W 8   0   sda          1       4   0.31
30513  npm              W 8   0   sda          1       4   0.30
30343  cp               W 8   0   sda          1       4   0.28
30567  cat              W 8   0   sda          1       4   0.30
0                       R 0   0   ?            2       0   0.18

BPF本を読みながら学ぶ8

8章、 ファイルシステムについて

目次

用語

  • Read Ahead
    • シーケンシャルなアクセスを行う際に、次に読み込まれるページを先に読み込み、パフォーマンスを向上させる
    • readahead syscall
  • Write Back
    • ディスクによるI/Oで、アプリケーションをブロックしないように、バッファをメモリに書き込んで、カーネルのワーカースレッドによってディスクへフラッシュする

ファイルシステムのキャッシュ

  • ページキャッシュ
    • ファイルとI/Oバッファーの内容(バッファーキャッシュ)を含む仮想メモリページが含まれ、ファイルおよびディレクトリI/Oのパフォーマンスが向上する
  • inodeキャッシュ
    • ファイルに対しての権限チェックやその他のメタデータを頻繁に読み込むために使用する
  • ディレクトリキャッシュ
    • ディレクトリエントリ名からVFS inodeへのマッピングをキャッシュ、パス名によるルックアップのパフォーマンスを向上させる

ディスクのパフォーマンス分析

  1. ファイルシステムの特定をする df / mount
  2. ファイルシステムの容量を確認する ファイルシステム次第では使用量が100%に近づくにつれ、検索アルゴリズムによるパフォーマンスの問題が発生する
    1. ZFSは80%未満が良い
  3. fioを使ってアイドル状態のシステムで既知のファイルシステムのワークロードを再現する
  4. opensnoopを実行して開いているファイルを確認する
  5. filelifeを実行して、寿命の短いファイルを確認する
  6. 異常に遅いファイルシステムへのI/Oを特定する ext4slower / btrfsslower / zfsslower / fileslower
  7. ファイルシステムのレイテンシの分布を調べる ext4dist / btrfsdist / zfsdist
  8. ページキャッシュのヒット率を調べる cachestat
  9. 論理I/Oと物理I/Oのレートを比較する(基本的には論理I/O > 物理I/Oが高いことが望ましい) vfsstat
  10. bpftoolを実行する

df

ファイルシステムのディスクスペースの使用量を表示する

❯ df -h
Filesystem      Size  Used Avail Use% Mounted on
udev            3.9G     0  3.9G   0% /dev
tmpfs           796M  1.9M  794M   1% /run
/dev/sda1       290G  110G  167G  40% /
tmpfs           3.9G     0  3.9G   0% /dev/shm
tmpfs           5.0M  4.0K  5.0M   1% /run/lock
tmpfs           3.9G     0  3.9G   0% /sys/fs/cgroup
/dev/loop0       90M   90M     0 100% /snap/core/8213
/dev/loop1       11M   11M     0 100% /snap/kubectl/1357
/dev/loop2       90M   90M     0 100% /snap/core/8268
/dev/loop3       11M   11M     0 100% /snap/kubectl/1373
/dev/loop4      100M  100M     0 100% /snap/bpftrace/29
tmpfs           796M   20K  796M   1% /run/user/1000

mount

マウントされた全てのファイルシステムを表示する

❯ mount
sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
udev on /dev type devtmpfs (rw,nosuid,relatime,size=4045620k,nr_inodes=1011405,mode=755)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
tmpfs on /run type tmpfs (rw,nosuid,noexec,relatime,size=814152k,mode=755)
/dev/sda1 on / type ext4 (rw,relatime,errors=remount-ro)

fatrace

システム全体のファイルアクセスイベントを表示する
プロセス名(プロセスID): イベントタイプ ファイルパス

オプション

-t タイムスタンプの表示
-p PID 指定したプロセスを除外する

イベントタイプ

O Open
R Read
W Write
C Close
❯ sudo fatrace
chrome(4527): O /home/atrophy/.cache/google-chrome/Default/Cache/index-dir/temp-index
chrome(4527): CW /home/atrophy/.cache/google-chrome/Default/Cache/index-dir/temp-index
vmtoolsd(736): W /var/log/vmware-vmsvc-root.log
chrome(4471): CWO /home/atrophy/.config/google-chrome/Default/.com.google.Chrome.g1yHPA
chrome(4471): CWO /home/atrophy/.config/google-chrome/.com.google.Chrome.c6ba3F
chrome(4471): W /home/atrophy/.config/google-chrome/Default/.com.google.Chrome.g1yHPA
chrome(4471): CW /home/atrophy/.config/google-chrome/Local State
chrome(4471): CW /home/atrophy/.config/google-chrome/Default/Preferences
gnome-terminal-(3903): RCO /usr/share/icons/ubuntu-mono-dark/actions/16/window-close-symbolic.svg
gnome-terminal-(3903): R /usr/share/icons/ubuntu-mono-dark/actions/16/window-close-symbolic.svg
gnome-terminal-(3903): C /usr/share/icons/ubuntu-mono-dark/actions/16/window-close-symbolic.svg
gnome-terminal-(3903): O /usr/share/icons/Adwaita/scalable/actions/tab-new-symbolic.svg
gnome-terminal-(3903): RC /usr/share/icons/Adwaita/scalable/actions/tab-new-symbolic.svg
gnome-terminal-(3903): RO /usr/share/icons/Adwaita/scalable/actions/tab-new-symbolic.svg
gnome-terminal-(3903): C /usr/share/icons/Adwaita/scalable/actions/tab-new-symbolic.svg
gnome-terminal-(3903): RCO /usr/share/icons/Adwaita/scalable/actions/pan-down-symbolic.svg
gnome-terminal-(3903): C /usr/share/icons/Adwaita/scalable/actions/pan-down-symbolic.svg
pool(7940): RCO /etc/nsswitch.conf
pool(7940): CO /etc/ld.so.cache
pool(7940): RO /lib/x86_64-linux-gnu/libnss_compat-2.27.so
pool(7940): RO /lib/x86_64-linux-gnu/libnss_nis-2.27.so
pool(7940): RO /lib/x86_64-linux-gnu/libnsl-2.27.so
pool(7940): RO /lib/x86_64-linux-gnu/libnss_files-2.27.so
pool(7940): CO /etc/group
pool(7940): O /bin/bash
pool(7940): R /bin/bash
pool(7940): RO /lib/x86_64-linux-gnu/ld-2.27.so
bash(7940): C /lib/x86_64-linux-gnu/libnss_compat-2.27.so
bash(7940): C /lib/x86_64-linux-gnu/libnss_nis-2.27.so
bash(7940): C /lib/x86_64-linux-gnu/libnsl-2.27.so
bash(7940): C /lib/x86_64-linux-gnu/libnss_files-2.27.so

statsnoop

stat() syscallをトレースし、どのプロセスがどのファイルに関する情報を読み取ろうとしているかを表示する

オプション

-x 失敗した統計のみ表示
-t タイムスタンプの表示
-p PID 指定したプロセスのみ表示

フィールド

TIME 呼び出し時間(秒単位)
PID プロセスID
COMM プロセス名
FD ファイルディスクリプタ(失敗時は-1)
ERR Error number(errno.h)
PATH 開いたパス
❯ sudo /usr/share/bcc/tools/statsnoop -t
TIME(s)       PID    COMM               FD ERR PATH
0.000000000   736    vmtoolsd            0   0 /etc/vmware-tools/tools.conf
0.000445262   13535  statsnoop          -1   2 /usr/lib/python2.7/encodings/ascii
1.975937867   3583   vmtoolsd            0   0 /etc/vmware-tools/tools.conf
5.000724336   736    vmtoolsd            0   0 /etc/vmware-tools/tools.conf
6.743327313   13310  ThreadPoolForeg     0   0 /etc/resolv.conf
6.743624226   729    systemd-resolve     0   0 /etc/hosts
6.743682672   729    systemd-resolve     0   0 /etc/resolv.conf
6.743698833   729    systemd-resolve     0   0 /etc/resolv.conf
6.977109934   3583   vmtoolsd            0   0 /etc/vmware-tools/tools.conf
10.002457003  736    vmtoolsd            0   0 /etc/vmware-tools/tools.conf

syncsnoop

ファイルシステムバッファをストレージデバイスにフラッシュするsync() syscallをトレースする

フィールド

TIME(s) 呼び出し時間(秒単位)
CALL 呼び出しのトレース
❯ sudo /usr/share/bcc/tools/syncsnoop
TIME(s)            CALL
23751.034417000    sync()
23751.770298000    sync()
23752.147148000    sync()
23752.378717000    sync()
23755.794625000    sync()
23759.138742000    sync()

filelife

ファイルの作成と削除をトレースし、ファイルを削除したユーザー、ファイルの経過時間、ファイル名に関する情報を表示する

オプション

-p PID 指定したプロセスのみ表示

フィールド

TIME 削除された時刻
PID ファイルを削除したプロセスID
COMM プロセス名
AGE(s) 作成されてから削除されるまでの時間(秒単位)
FILE ファイル名
❯ sudo /usr/share/bcc/tools/filelife 
TIME     PID    COMM             AGE(s)  FILE
00:09:36 16063  bash             0.00    sh-thd.aglEmZ
00:09:36 18969  rm               4.36    hoge
00:09:45 18610  anacron          0.00    fileNpHdSz
00:09:45 495    systemd-udevd    0.00    queue
00:09:45 495    systemd-udevd    0.00    queue
00:09:45 495    systemd-udevd    0.00    queue
00:09:45 495    systemd-udevd    0.00    queue
00:09:45 19187  gpg              0.00    .#lk0x000055fe6b0679f0.ubuntu.19
00:09:45 19187  gpg              0.00    .#lk0x000055fe6b066f70.ubuntu.19
00:09:45 495    systemd-udevd    0.00    queue
00:09:45 19191  gpg              0.00    .#lk0x000055ebc43c8e70.ubuntu.19
00:09:45 19253  rm               0.05    trustdb.gpg
00:09:45 19253  rm               0.05    pubring.kbx
00:09:45 19253  rm               0.05    pubring.gpg

vfscount

VFS呼び出しをカウントする
VFSへの操作の一般的なワークロードの特性評価に役立つ

フィールド

ADDR トレースされた命令ポインタ(instruction pointer)のアドレス
FUNC カーネルのファンクション名
COUNT トレース中に呼び出された回数
❯ sudo /usr/share/bcc/tools/vfscount 10
Tracing... Ctrl-C to end.

ADDR             FUNC                          COUNT
ffffffffa7af28f1 vfs_statfs                        1
ffffffffa7ac5b01 vfs_unlink                        3
ffffffffa7aefd91 vfs_fsync_range                   5
ffffffffa7ac4651 vfs_rmdir                         7
ffffffffa7b1df91 vfs_lock_file                    24
ffffffffa7acb121 vfs_readlink                     49
ffffffffa7ab7a11 vfs_write                       274
ffffffffa7abc3d1 vfs_statx                       299
ffffffffa7ab5de1 vfs_writev                      325
ffffffffa7ab7751 vfs_read                        365
ffffffffa7abc351 vfs_statx_fd                    868
ffffffffa7ab3541 vfs_open                       1100
ffffffffa7abc311 vfs_getattr                    1133
ffffffffa7abc281 vfs_getattr_nosec              1139

fileslower

VFSインターフェイスで同期読み取りおよび書き込みをカーネルの動的トレースを使用して、
ファイルシステムへの遅いファイル読み込みと書き込みを見分ける

フィールド

TIME(s) 最初のI/Oが開始してからI/Oが完了するまでにかかった時間(秒単位)
COMM プロセス名
PID プロセスID
D I/Oの方向
R(Read)
W(write)
BYTES I/Oのサイズ
LAT(ms) I/Oのlatency
FILENAME キャッシュされたカーネルのファイル名(dentry->d_iname)
❯ sudo /usr/share/bcc/tools/fileslower 
Tracing sync read/writes slower than 10 ms
TIME(s)  COMM           TID    D BYTES   LAT(ms) FILENAME
26.288   dd             21861  W 1048576   10.30 swapfile
26.979   dd             21861  W 1048576   11.35 swapfile
28.525   dd             21861  W 1048576   38.75 swapfile
28.622   dd             21861  W 1048576   11.50 swapfile
28.644   dd             21861  W 1048576   12.38 swapfile
28.682   dd             21861  W 1048576   30.95 swapfile
28.698   dd             21861  W 1048576   15.74 swapfile
28.720   dd             21861  W 1048576   19.20 swapfile

filetop

プロセスとファイル名による読み込みと書き込み
Topコマンドのファイル版

オプション

-a 通常ファイル以外のファイルタイプも含める(sockets, FIFOs, etc)
-p PID 指定したプロセスのみ表示

フィールド

loadavg /proc/loadavgの内容
TID スレッドID
COMM プロセス名
READS インターバル中の読み込み回数
WRITES インターバル中の書き込み回数
R_Kb インターバル中の読み込み(Kbytes)の合計
W_Kb インターバル中の書き込み(Kbytes)の合計
T ファイルのタイプ
R(Regular)
S(Socket)
O(Other(pipe, etc))
❯ sudo /usr/share/bcc/tools/filetop -a

01:10:17 loadavg: 0.05 0.11 0.07 1/725 22487

TID    COMM             READS  WRITES R_Kb    W_Kb    T FILE
3903   gnome-terminal-  8      1      62      0       O ptmx
1707   InputThread      8      0      56      0       O event1
22487  clear            2      0      8       0       R xterm-256color
3404   gmain            2      0      8       0       O inotify
22484  filetop          2      0      2       0       R loadavg
22487  clear            1      0      0       0       R libtinfo.so.5.9
22487  clear            1      0      0       0       R libc-2.27.so
22487  filetop          3      0      0       0       R clear
22487  filetop          2      0      0       0       R ld-2.27.so
3188   gdbus            12     28     0       0       O [eventfd]
3279   gdbus            6      10     0       0       O [eventfd]
3903   gnome-terminal-  7      8      0       0       O [eventfd]
3312   gnome-shell      6      8      0       0       O [eventfd]
3905   gdbus            6      8      0       0       O [eventfd]
3180   ibus-daemon      8      4      0       0       O [eventfd]
1127   acpid            6      0      0       0       O event1
22484  filetop          0      3      0       0       O 0
3404   gmain            2      6      0       0       O [eventfd]
3275   ibus-engine-sim  2      2      0       0       O [eventfd]
3903   gnome-terminal-  0      2      0       0       O [eventfd]

dcstat

ディレクトリエントリキャッシュ(dcache)の統計

フィールド

TIME タイムスタンプ
REFS/s dcacheのルックアップ数(秒間)
SLOW/s lookup_fast()に失敗し、
代わりにlookup_slow()を実行したdcacheのルックアップ数(秒間)
MISS/s ミス数(lookup_fast/lookup_slowの両方に失敗した場合)
HIT% dcacheのヒット率
❯ sudo /usr/share/bcc/tools/dcstat
TIME         REFS/s   SLOW/s   MISS/s     HIT%
01:21:12:        36        0        0   100.00
01:21:13:         8        0        0   100.00
01:21:14:        66        0        0   100.00
01:21:15:       404        0        0   100.00
01:21:16:        13        0        0   100.00
01:21:17:        40        0        0   100.00
01:21:18:        63        1        0   100.00
01:21:19:        23        0        0   100.00
01:21:20:      7218       72       63    99.13
01:21:21:         8        0        0   100.00

dcsnoop

ディレクトリエントリキャッシュ(dcache)ルックアップをトレースする

オプション

-a 失敗したルックアップだけでなく、参照もトレースに含める

フィールド

TIME(s) ルックアップした時間(秒単位)
PID プロセスID
COMM プロセス名
T タイプ
R(Reference) -aオプションの場合のみ表示
M(Miss)
FILE ルックアップしていたファイル名コンポーネント
❯ sudo /usr/share/bcc/tools/dcsnoop -a
TIME(s)     PID    COMM             T FILE
0.097416    3481   gsd-color        R etc/localtime
0.097488    3481   gsd-color        R localtime
0.097515    3481   gsd-color        R usr/share/zoneinfo/Asia/Tokyo
# 省略
0.097779    23215  dcsnoop          R usr/lib/python2.7/encodings/ascii
0.097786    23215  dcsnoop          R lib/python2.7/encodings/ascii
0.097809    23215  dcsnoop          R python2.7/encodings/ascii
# 省略
0.753587    1175   gmain            R extrausers
0.753599    1211   gmain            R etc/NetworkManager/VPN
0.753622    1211   gmain            R NetworkManager/VPN
0.753634    1211   gmain            R VPN
# 省略
4.666200    23163  ThreadPoolForeg  M .com.google.Chrome.LWOyo3

mountsnoop

mount() および umount() syscallをトレースする

COMM プロセス名
PID プロセスID
TID スレッドID
MNT_NS マウントしているnamespaceのinode number
CALL syscall、引数、戻り値
❯ sudo /usr/share/bcc/tools/mountsnoop 
COMM             PID     TID     MNT_NS      CALL
dockerd          1329    2575    4026531840  mount("overlay", "/var/lib/docker/overlay2/f606e18c5811d17fbe31ae16d76af01a3a1c77f6e72c031137d98499c79d3ebb-init/merged", "overlay", MS_NOSUID|MS_NOEXEC|MS_REMOUNT|MS_MANDLOCK|MS_MOVE|MS_REC|MS_SILENT|MS_POSIXACL|MS_UNBINDABLE|MS_PRIVATE|MS_LAZYTIME|MS_NOUSER|0x564510000200, "") = 0
dockerd          1329    1714    4026531840  mount("overlay", "/var/lib/docker/overlay2/b9dc1b32c519d1567f91049d638141703d05795dedd49d371628d8a6c3d4ed30-init/merged", "overlay", MS_NOSUID|MS_NOEXEC|MS_REMOUNT|MS_MANDLOCK|MS_MOVE|MS_REC|MS_SILENT|MS_POSIXACL|MS_UNBINDABLE|MS_PRIVATE|MS_LAZYTIME|MS_NOUSER|0x564510000200, "") = 0
dockerd          1329    1673    4026531840  mount("overlay", "/var/lib/docker/overlay2/accc5ace809c7b6f253c0ba6aabea824b16555b78b482687a3fc4bd95fd8c1f8-init/merged", "overlay", MS_NOSUID|MS_NOEXEC|MS_REMOUNT|MS_MANDLOCK|MS_MOVE|MS_REC|MS_SILENT|MS_POSIXACL|MS_UNBINDABLE|MS_PRIVATE|MS_LAZYTIME|MS_NOUSER|0x564510000200, "") = 0
dockerd          1329    1563    4026531840  mount("overlay", "/var/lib/docker/overlay2/5c2f7a8d49bfc977691083b40801307c929632baa9de64acbeb1acc26d0016b7-init/merged", "overlay", MS_NOSUID|MS_NOEXEC|MS_REMOUNT|MS_MANDLOCK|MS_MOVE|MS_REC|MS_SILENT|MS_POSIXACL|MS_UNBINDABLE|MS_PRIVATE|MS_LAZYTIME|MS_NOUSER|0x564510000200, "") = 0
dockerd          1329    1563    4026531840  umount("/var/lib/docker/overlay2/5c2f7a8d49bfc977691083b40801307c929632baa9de64acbeb1acc26d0016b7-init/merged", MNT_DETACH) = 0
dockerd          1329    2575    4026531840  umount("/var/lib/docker/overlay2/f606e18c5811d17fbe31ae16d76af01a3a1c77f6e72c031137d98499c79d3ebb-init/merged", MNT_DETACH) = 0
dockerd          1329    1673    4026531840  umount("/var/lib/docker/overlay2/accc5ace809c7b6f253c0ba6aabea824b16555b78b482687a3fc4bd95fd8c1f8-init/merged", MNT_DETACH) = 0
dockerd          1329    1714    4026531840  umount("/var/lib/docker/overlay2/b9dc1b32c519d1567f91049d638141703d05795dedd49d371628d8a6c3d4ed30-init/merged", MNT_DETACH) = 0
dockerd          1329    2575    4026531840  mount("overlay", "/var/lib/docker/overlay2/f606e18c5811d17fbe31ae16d76af01a3a1c77f6e72c031137d98499c79d3ebb/merged", "overlay", MS_NOSUID|MS_NOEXEC|MS_REMOUNT|MS_MANDLOCK|MS_MOVE|MS_REC|MS_SILENT|MS_POSIXACL|MS_UNBINDABLE|MS_PRIVATE|MS_LAZYTIME|MS_NOUSER|0x564510000200, "") = 0

ext4dist

ext4操作のレイテンシを要約する

フィールド

usecs マイクロ秒の範囲
count 範囲内のオペレーションの回数
distribution カウントの分布
❯ sudo /usr/share/bcc/tools/ext4dist
Tracing ext4 operation latency... Hit Ctrl-C to end.

operation = read
     usecs               : count     distribution
         0 -> 1          : 290      |****************************************|
         2 -> 3          : 11       |*                                       |
         4 -> 7          : 3        |                                        |
         8 -> 15         : 4        |                                        |
        16 -> 31         : 1        |                                        |

operation = write
     usecs               : count     distribution
         0 -> 1          : 1        |****************************************|
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 1        |****************************************|

operation = open
     usecs               : count     distribution
         0 -> 1          : 175      |****************************************|
         2 -> 3          : 5        |*                                       |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 1        |                                        |

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