皆さんは公開情報ですか？（挨拶）
初めに言いたいこと
タイトルの通りのワークショップを始めます。最初は福岡市内でオンサイトで、エンジニアカフェ[PR]でやっていくので、まずはぜひ福岡近辺のソフトウェアに関わるエンジニアに届いてほしい。
OSS Halfway とは？
以下、OSS Halfwayを始めるにあたって考えたことをつらつらと書いてみます。何かの参考になるかは分かりません。とにかく届いてほしい、来てくれ。
続きを読むSlackのInteractionCallbackに含まれるMessageからもとのURLを復元する
10月何もしていない...（会社のブログはギリギリ書いた記憶がある）。
何もしなすぎてるので極小ネタを。
SlackのAppにはUser Interactionという機能があり、例えばSlackの入力画面からのショートカット実行結果を受け取り、フォームを返したりさらに入力を受け取ったりなんやかんやできる。
この辺にまとまってる通りなのだけど、メッセージに紐づくショートカット（メッセージ右上のメニューから実行できるやつ）には、元のメッセージの情報がInteractionCallbackとして含まれている。例えばGoのコードならこういう感じで取れる。
payload := new(slack.InteractionCallback) err := json.Unmarshal(getPayloadFormValue()), payload) if err != nil { ... } fmt.Printf("%v\n", payload.Message)
ところで、このMessageには元メッセージのURLがそのものズバリでは含まれていない模様。
例えばショートカットがAcceptされた通知として、元のメッセージのURLを含むポストをする（そうすると元メッセージも引用されるし）などをしたい場合、以下のようなコードを書くしかない。
workspace := "myworkspace" chanId := payload.Channel.ID slug := "p" + strings.ReplaceAll(payload.Message.Timestamp, ".", "") url := fmt.Sprintf("https://%s.slack.com/archives/%s/%s", workspace, chanId, slug)
メッセージのURLにはタイムスタンプの情報が含まれている模様（今はそういう仕様なだけ？）。
なおスレッドのパーマリンクの場合、また別のタイムスタンプ Message.ThreadTimestamp がある。
やりたいことに対し情報がなかったので残しとく。
RubyKaigi 後日譚: GC のレイテンシを可視化する人の補足
本日RubyKaigiでお話ししてきました。BPFのObservability関連の機能を紹介しながら実際にサンプルをRubyで書いていくみたいな流れでした。以下に資料を。
一番見せたかった「RubyのGC関係USDTを用いてレイテンシを可視化する」というツールのデモが...流せなかったので*1、心残りを洗い流すべく補足記事を書きます。
USDT？
Rubyを特定のオプション --enable-dtrace でconfigureしてビルドすると、USDTと呼ばれる情報がRubyのバイナリに付与されます。この情報を使うとRubyの生きているプログラムに対して、さまざまな細かい情報を取得できるようになります。例えば以下のタイミングでイベントがフックされます。
- オブジェクト一般、シンボル、文字列、配列、ハッシュの作成
- C定義のメソッドの呼び出し、リターン
- GCの開始、終了
- 例外発生
そもそもTracePointという機構もありますが、TracePointがプログラムパフォーマンスに大きく影響を与えることは周知のことです。USDT経由で、かつBPFのような仕組みで情報を取得すると実用上影響ないレベルの副作用で細かい情報が取得できます。はず。
ところでUSDTを調べていると「dtrace」という言葉がよく出てきますが、USDTという概念はそもそもDTraceの文脈で出てきたもののようで、それをLinuxでも使えるようにした感じで進化してきたもの*2みたいです。
詳細は、aaronによるるびまのDTrace紹介（first introduced in 2.0なんですよね / 全く同じProbeが使えます）、
kosakiさんによる解説などをどうぞ。
作ったもの
生きているRubyプロセスに対してアタッチし、1秒ごとに以下を表示します。
$ sudo ruby ./gcsnoop.rb 186197 $(rbenv which ruby) Start tracing TIME EVENT RSS(KB) ELAPSED(ms/event) 2022-09-09 15:22:52.487468 RSS 23372 2022-09-09 15:22:53.500447 MARK - 2022-09-09 15:22:53.505751 SWEEP - 2022-09-09 15:22:53.531737 RSS 23204 2022-09-09 15:22:54.603751 MARK - 2022-09-09 15:22:54.604788 SWEEP - 2022-09-09 15:22:54.637420 RSS 23444 2022-09-09 15:22:55.712456 MARK - 2022-09-09 15:22:55.712677 SWEEP 0.250, 1 time(s) 2022-09-09 15:22:55.740717 RSS 23588 2022-09-09 15:22:56.799344 MARK - 2022-09-09 15:22:56.801217 SWEEP - 2022-09-09 15:22:56.834391 RSS 23672 2022-09-09 15:22:57.908051 MARK - 2022-09-09 15:22:57.908299 SWEEP 0.149, 1 time(s) 2022-09-09 15:22:57.941105 RSS 23756
実験としてわざとメモリリークするようなSinatraのアプリを書きました。これはひどいですが、実験です。
require 'sinatra' $count = 0 $leak = [] $next = 100 puts "LEAK MODE: #{! ENV["LEAKY"].nil?}" get '/' do if ENV["LEAKY"] $leak << (1..100).map { Object.new } end "OK" end
$ LEAKY=1 ruby sinatra-app.rb 2>/dev/null &
LEAK MODE: true
Puma starting in single mode...
* Puma version: 5.6.5 (ruby 3.1.2-p20) ("Birdie's Version")
* Min threads: 0
* Max threads: 5
* Environment: development
* PID: 187396
* Listening on http://127.0.0.1:4567
* Listening on http://[::1]:4567
Use Ctrl-C to stop
$ ps auxf | grep -e RSS -e puma
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
ubuntu 187441 1.0 0.3 363388 26396 pts/3 Sl 15:26 0:00 | \_ puma 5.6.5 (tcp://localhost:4567) [rk2022-benchtools]
$ ab -c 1000 -t 10 http://127.0.0.1:4567/
...
$ ps auxf | grep -e RSS -e puma
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
ubuntu 187515 33.5 3.6 855116 295512 pts/3 Sl 15:27 0:21 | \_ puma 5.6.5 (tcp://localhost:4567) [rk2022-benchtools]
簡単にRSSを肥大化させることができます。GCがどうなるか見てみます。
$ sudo ruby ./gcsnoop.rb 187441 $(rbenv which ruby) Start tracing TIME EVENT RSS(KB) ELAPSED(ms/event) 2022-09-09 15:30:01.415746 RSS 22860 2022-09-09 15:30:02.489423 MARK - 2022-09-09 15:30:02.489839 SWEEP - 2022-09-09 15:30:02.526016 RSS 22860 ... 2022-09-09 15:30:28.291423 RSS 22860 2022-09-09 15:30:29.292707 MARK 0.552, 17 time(s) 2022-09-09 15:30:29.292734 SWEEP 0.055, 254 time(s) 2022-09-09 15:30:29.297429 RSS 49260 2022-09-09 15:30:30.298606 MARK 1.274, 6 time(s) 2022-09-09 15:30:30.298636 SWEEP 0.060, 247 time(s) 2022-09-09 15:30:30.304768 RSS 63364 2022-09-09 15:30:31.306836 MARK 1.408, 4 time(s) 2022-09-09 15:30:31.306866 SWEEP 0.059, 255 time(s) 2022-09-09 15:30:31.311147 RSS 83784 2022-09-09 15:30:32.312385 MARK 2.297, 2 time(s) 2022-09-09 15:30:32.312416 SWEEP 0.061, 230 time(s) 2022-09-09 15:30:32.317398 RSS 111252 2022-09-09 15:30:33.318531 MARK 4.285, 2 time(s) 2022-09-09 15:30:33.318559 SWEEP 0.067, 195 time(s) ... 2022-09-09 15:30:47.433592 RSS 389912 2022-09-09 15:30:48.434317 MARK 14.691, 1 time(s) 2022-09-09 15:30:48.434350 SWEEP 0.093, 187 time(s) 2022-09-09 15:30:48.441605 RSS 423512 2022-09-09 15:30:49.442609 MARK 2.361, 1 time(s) 2022-09-09 15:30:49.442659 SWEEP 0.072, 306 time(s) 2022-09-09 15:30:49.450451 RSS 425004 2022-09-09 15:30:50.451657 MARK - 2022-09-09 15:30:50.451685 SWEEP 0.078, 336 time(s) 2022-09-09 15:30:50.459964 RSS 432168 2022-09-09 15:30:51.461260 MARK 14.032, 1 time(s) 2022-09-09 15:30:51.461293 SWEEP 0.084, 256 time(s) 2022-09-09 15:30:51.468487 RSS 449268 2022-09-09 15:30:52.469774 MARK - 2022-09-09 15:30:52.469803 SWEEP 0.057, 171 time(s) 2022-09-09 15:30:52.477342 RSS 473020 2022-09-09 15:30:53.478389 MARK 15.491, 1 time(s) 2022-09-09 15:30:53.478409 SWEEP 0.077, 391 time(s) 2022-09-09 15:30:53.485416 RSS 480392 2022-09-09 15:30:54.486348 MARK 16.764, 1 time(s) 2022-09-09 15:30:54.486378 SWEEP 0.078, 160 time(s) 2022-09-09 15:30:54.494123 RSS 512272 2022-09-09 15:30:55.495602 MARK - 2022-09-09 15:30:55.495634 SWEEP 0.066, 414 time(s) 2022-09-09 15:30:55.503252 RSS 513088 2022-09-09 15:30:56.504433 MARK 18.446, 1 time(s) 2022-09-09 15:30:56.504460 SWEEP 0.096, 149 time(s) ... ... 2022-09-09 15:31:46.065511 RSS 1165324 2022-09-09 15:31:47.066567 MARK 34.956, 1 time(s) 2022-09-09 15:31:47.066786 SWEEP 0.104, 135 time(s)
RSSが大きくなる（＝Mark対象のオブジェクトが増える）とMarkフェーズの所要時間が増えていっていることが観測できます。RSSが1GBに達したら30ms超えになっているようです。なお、Sweepの対象が増えるわけではないためかそちらへの影響はそこまで大きくありません。
動画も作っています。以下です。
RSSの計算にはprocfsの情報を、そしてMark/Sweepの回数とレイテンシの計測にUSDTと、BPF、RbBCCを使いました。
そしてこのツール自体は USDT有効ビルドのRubyを使っていればどんなアプリケーションにも使える ので、現場のpumaやfluentdのGCレイテンシの計測にそのまま使えるかもしれません。USDT有効ビルドのRubyを準備するのがそれなりにハードルですが挑戦してみてください。
コードの全体は こちら です。
Observability用途のBPFを活用する際、例えばファイルアクセスやネットワークのレイテンシなどを計測するにしても、前提としてカーネル内部の知識が必要になりがちです。一方USDTやuprobeであれば、対象アプリケーションの中身がわかっていれば活用できます。いろいろな用途が見つかるといいなと思います。
と言いたかった。
会期はまだまだ残っていて、私も会場をうろうろとしていますので、興味のある方はお声がけください！
PyRoute2 + PyCall.rb でネットワークインタフェースの操作をする
前回、BCCのPythonバインディングで、TCにBPFを引っ掛けてegressのIPを表示した。
ところで私はRuby版BCCを開発しているわけだが、上記プログラムは一部iproute2的な操作をPythonで行うPyroute2に依存している。RubyにはPyroute2に相当するgemが開発されていないので動かせない。RbBCCの対象範囲はBPFプログラム作成側だけなので。
...と思っていたが、PyCall.rbというものの存在を思い出した（以下単にPyCallというときはRuby版）。PyCallは主にPythonの数値計算や機械学習関連のライブラリを呼び出すときに使われている印象があるが、Pyroute2を呼び出してみる。
続きを読むBCCでTCにアタッチし、egressのIPを表示する
サーバではいろいろな通信があるけれど、実際どんな通信が行われているか全貌を確認するのはなかなか難しい。
上記のソリューションはかっこいいが、KRSIなんで、「うちの環境のカーネルじゃちょっと...」となりがち。BPFあるあるだと思う。
一方でBPF自体は、カーネルでサポートされて随分時間が経ってきており、徐々に使えるカーネルが普及してきた。
とりあえず通信のログを残したい、というだけであればTCにBPFをアタッチする方法も使えて、これはUbuntu 20.04のカーネル（5.4 〜 5.8）なら十分使える。
// よく考えたらTCなのでブロックもできるのかな？
まあ今度調べるとして、egressの通信をキャプチャしてdst IP（今回はv4だけです）を集計するサンプルを残す。
動作環境（主にカーネルバージョン）について
今回は別の環境カーネル5.4でも動作確認しま。もう少し低くても行けるかもしれない。
しかしこのブログの環境は以下。
ubuntu@udzura.local:~$ uname -a Linux kondo-ke-focal 5.8.0-63-generic #71~20.04.1-Ubuntu SMP Thu Jul 15 17:46:44 UTC 2021 aarch64 aarch64 aarch64 GNU/Linux
BCC の環境を作る
BCCといえば自作ビルド... という時代もあったが、今回はパッケージマネージャー経由のもので十分。
$ apt install libbpfcc python3-bpfcc python3-pyroute2
Ubuntu 20.04 では libbcc 0.12.0 が入ってくる。
自分の環境は全然違うディストリです！という場合はいっそ --host=net でdebianを立ち上げてもいいと思う。
$ docker run -ti --rm -v /lib/modules:/lib/modules -v /usr/src:/usr/src --privileged --net=host debian:11-slim ~# apt update && apt install libbpfcc python3-bpfcc python3-pyroute2
多分動く。debian 11 では libbcc 0.18.0 が入ってくる。
Python のスクリプト
いろいろな実装のつぎはぎだが、これを動かす。
from bcc import BPF, libbcc from struct import unpack import pyroute2 import time import sys code = """ // SPDX-License-Identifier: GPL-2.0+ #define BPF_LICENSE GPL #include <linux/pkt_cls.h> #include <uapi/linux/bpf.h> #include <bcc/proto.h> BPF_HASH(ip_counter, u32, u64); int counter(struct __sk_buff *skb) { u32 key = 0; u8 *cursor = 0; struct ethernet_t *ethernet = cursor_advance(cursor, sizeof(*ethernet)); // 0x0800 = IPv4 if (ethernet->type != 0x0800) return TC_ACT_OK; struct ip_t *ip = cursor_advance(cursor, sizeof(*ip)); key = ip->dst; if (key == 0) return TC_ACT_OK; // 192.168.0.0 ~ 192.168.255.255 のログは取らない // 他のプライベートIPレンジは宿題とします。 if (3232235520 <= key && key <= 3232301055) return TC_ACT_OK; u64 zero = 0; u64 *value = ip_counter.lookup_or_try_init(&key, &zero); if (value) *value += 1; return TC_ACT_OK; } """ # ライブラリを知らないので頑張って自作した def int_to_ip(nr_): nr = unpack('I', nr_)[0] return '{}.{}.{}.{}'.format( (nr >> 24 & 0b11111111), (nr >> 16 & 0b11111111), (nr >> 8 & 0b11111111), (nr & 0b11111111) ) def count(nr_): return unpack('L', nr_)[0] def count_packet(iface): bpf = BPF(text=code, cflags=["-w"]) func = bpf.load_func("counter", BPF.SCHED_CLS) counter = bpf.get_table("ip_counter") print("map fd: {}".format(counter.map_fd)) ip = pyroute2.IPRoute() ipdb = pyroute2.IPDB(nl=ip) idx = ipdb.interfaces[iface].index ip.tc("add", "clsact", idx) # ffff:fff3 というのが、 egress のことらしい。 # ingress なら ffff:fff2 らしい。 ip.tc("add-filter", "bpf", idx, ":1", fd=func.fd, name=func.name, parent="ffff:fff3", classid=1, direct_action=True) print("Hit CTRL+C to stop") while True: try: print("outgoing dest ips in 1s:") for k, v in counter.items(): print(f'k: {int_to_ip(k)}, v: {count(v)}') counter.clear() time.sleep(1) except KeyboardInterrupt: print("Removing filter from device") break ip.tc("del", "clsact", idx) ipdb.release() if __name__ == '__main__': iface = sys.argv[1] count_packet(iface)
※ ところで拙作 RbBCC ではこれと同じことができない。libbccのFFIなので本当はできるはずだが、pyroute2のRuby版がないのでBPFプログラムを作れてもアタッチできない。pyroute2は巨大なので流石に僕は移植する時間が...。
pyroute2がRubyにあると嬉しいなあという願いだけ残そう。
tcにアタッチする
上記をsudoで実行するとデバイスにアタッチできる。
$ sudo python3 filter.py enp0s1 map fd: 4 Hit CTRL+C to stop outgoing dest ips in 1s: outgoing dest ips in 1s: outgoing dest ips in 1s: outgoing dest ips in 1s:
この状態で、 enp0s1 を通って外に行くような通信をすると、ちゃんと記録されることがわかる。
$ ping hatena.ne.jp PING hatena.ne.jp (54.65.114.10) 56(84) bytes of data. 64 bytes from ec2-54-65-114-10.ap-northeast-1.compute.amazonaws.com (54.65.114.10): icmp_seq=1 ttl=232 time=36.1 ms 64 bytes from ec2-54-65-114-10.ap-northeast-1.compute.amazonaws.com (54.65.114.10): icmp_seq=2 ttl=232 time=32.1 ms ... outgoing dest ips in 1s: k: 54.65.114.10, v: 1 outgoing dest ips in 1s: k: 54.65.114.10, v: 1 ...
今回は雑然とMapに保存しているが、定期的に取り出して監査ログにするなり、怪しい通信を確認するなりやろうと思えばできそうかな？
トラブルシュート
tc にアタッチする前に、以下のコマンドで現在何もクラスがないことが確認できる。
$ tc qdisc show dev enp0s1 clsact qdisc fq_codel 0: root refcnt 2 limit 10240p flows 1024 quantum 1514 target 5.0ms interval 100.0ms memory_limit 32Mb ecn
上のスクリプトの実行が失敗すると、中途半端なクラスやフィルターが残る。
$ tc qdisc show dev enp0s1 clsact qdisc fq_codel 0: root refcnt 2 limit 10240p flows 1024 quantum 1514 target 5.0ms interval 100.0ms memory_limit 32Mb ecn qdisc clsact ffff: parent ffff:fff1 <- これ
削除は以下のコマンドで。
$ sudo tc qdisc del dev enp0s1 clsact
（実はこの記事の主題こと）宣伝
RubyKaigi 2022 で BPF の話をします。と言いつつこの記事でしているネットワーク関係の機能の話はしなくて、Observability中心です。
思えば2年以上前にとりあえず完成させたものですが、RbBCCの話中心に色々やっていくような気がします。正直、現場で運用にも携わる人としては、CO-REが普通に使えるカーネルに全部置き換えよう！ ってすぐにはいかないので、全然BCC使っていこうと思っていますから...。
今年はハイブリッド開催だそうです。できる形で是非ご参加くださいませ。赤福。
（今気づいたけど1行もRubyのコードがない記事で宣伝してるw）
