同僚の皆さんへのアンサーソングです。
RubyKaigi やらですっかり遅く... と思ったがRubyKaigi takeoutの振り返りも書いてない...
タイトルの通り（通り？）、forkしたプロセスがCoWをどれくらい起こしているか可視化するツールを作りました。
まだ私の理解が浅いところもあるのですが、いったん動作例などを掲示してみます。
hiboma.c の場合
上のhibomaさんのCoWのサンプルプログラムの例です。プロジェクトのmiscというディレクトリ の下に exec_waiter.rb という補助スクリプトを置いてあります。それを経由してプログラムを起動すると、親のPIDを表示して実行が停止します。
cowsnoop/misc$ ruby exec_waiter.rb ./hiboma Program "./hiboma" is waiting now to be traced. Please setup your BPF fantastic tools against: PID = 198039 Then - hit return to continue
別のターミナルで cowsnoop を起動します。
$ sudo ./mruby/bin/cowsnoop --track-first-clone 198039 Tracking first forked child.
戻って何かキーを押すと hiboma コマンドにexecするので、トレーサの方に戻ると、確かに1秒毎に1回のCoWの発生を検知しています。
mmap: 0x100000000000 parent pid:198039 child pid:198142 cow address: 0x100000000000 cow address: 0x100000001000 cow address: 0x100000002000 cow address: 0x100000003000 cow address: 0x100000004000 cow address: 0x100000005000 cow address: 0x100000006000 cow address: 0x100000007000 cow address: 0x100000008000 ...
[!] Tracking: child pid = 198142 [2021-09-24 15:40:02 +0000] 7: @@@@@@@ [2021-09-24 15:40:03 +0000] 1: @ [2021-09-24 15:40:04 +0000] 1: @ [2021-09-24 15:40:05 +0000] 1: @ [2021-09-24 15:40:06 +0000] 1: @ [2021-09-24 15:40:07 +0000] 1: @ [2021-09-24 15:40:08 +0000] 1: @ [2021-09-24 15:40:09 +0000] 1: @ [2021-09-24 15:40:10 +0000] 1: @ [2021-09-24 15:40:11 +0000] 1: @ [2021-09-24 15:40:12 +0000] 1: @ ...
Ruby のスクリプトの場合
以下のようなRubyスクリプトを作ります。ここにもアップしています。
puts "Current pid: #{$$} / Hit key to continue" gets $a = []; p Process.waitpid(fork do puts $$ loop do $a << Hash.new sleep 0.0001 end end)
これを同様に起動し、
$ ruby bigarray.rb Current pid: 198287 / Hit key to continue
トレースし、
$ sudo ./mruby/bin/cowsnoop --track-first-clone 198287 Tracking first forked child.
元のプログラムの起動を再開します。すると、子プロセス 198357 のCoWの発生を時系列で追うことができます。
[!] Tracking: child pid = 198357 [2021-09-24 15:43:53 +0000] 53: @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ [2021-09-24 15:43:54 +0000] 7: @@@@@@@ [2021-09-24 15:43:55 +0000] 3: @@@ [2021-09-24 15:43:56 +0000] 8: @@@@@@@@ [2021-09-24 15:43:57 +0000] 4: @@@@ [2021-09-24 15:43:58 +0000] 7: @@@@@@@ [2021-09-24 15:43:59 +0000] 5: @@@@@ [2021-09-24 15:44:00 +0000] 46: @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ [2021-09-24 15:44:01 +0000] 0: [2021-09-24 15:44:02 +0000] 383: @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ [2021-09-24 15:44:03 +0000] 0: [2021-09-24 15:44:04 +0000] 0: [2021-09-24 15:44:05 +0000] 0: [2021-09-24 15:44:06 +0000] 0: [2021-09-24 15:44:07 +0000] 0: [2021-09-24 15:44:08 +0000] 0: [2021-09-24 15:44:09 +0000] 0: [2021-09-24 15:44:10 +0000] 0: [2021-09-24 15:44:11 +0000] 0: [2021-09-24 15:44:12 +0000] 0: [2021-09-24 15:44:13 +0000] 25: @@@@@@@@@@@@@@@@@@@@@@@@@ [2021-09-24 15:44:14 +0000] 0: [2021-09-24 15:44:15 +0000] 0: [2021-09-24 15:44:17 +0000] 0: [2021-09-24 15:44:18 +0000] 1: @ [2021-09-24 15:44:19 +0000] 0: ...
この時、一緒に親子のVSZ/RSSをトラックすると、最初の方は子プロセスの方がもちろんRSSが小さい状態です。
$ ps auxf | grep -e RSS -e bigarray USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND vagrant 198287 0.0 0.2 78844 22136 pts/1 S+ 15:43 0:00 | \_ ruby bigarray.rb vagrant 198357 1.6 0.2 78844 19856 pts/1 S+ 15:43 0:00 | \_ ruby bigarray.rb vagrant 198369 0.0 0.0 8008 880 pts/2 S+ 15:44 0:00 \_ grep --color=auto -e RSS -e bigarray
プログラムの性質上、次第に子プロセスのRSSが肥大化していきます。また、どこかのタイミングでVSZも拡張します。
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND vagrant 198287 0.0 0.2 78844 22136 pts/1 S+ 15:43 0:00 | \_ ruby bigarray.rb vagrant 198357 1.8 0.2 79132 20080 pts/1 S+ 15:43 0:00 | \_ ruby bigarray.rb vagrant 198393 0.0 0.0 8008 816 pts/2 S+ 15:44 0:00 \_ grep --color=auto -e RSS -e bigarray
VSZが拡張したあたりで、CoWが一切起こらなくなる（すなわち、親子で共通の領域からはみ出たところにオブジェクトが作られはじめる？）、ということが確認できます。
cowsnoopに機能を追加すれば、元々の関心ごとだったunicornがワーカーごとにどれくらいCoWを発生させているのかという点が追いかけられるかもしれません。
ちなみにこのcowsnoopは、いわゆるBPF CO-REのトレースツールですが、mruby + libbpf で書いています。もちろんブリッジするコードはCで書いていますし、またBPFバイナリ部分は普通にというかCから作っています（Rucyはまだ全然実戦投入できません...）。
ですがトレーサのメイン部分をRubyで書けるというのは、僕にとって大変気分の良いことです。
また、トレーサのようなツールを書く際は結構探索的なコーディングをする傾向がある気がしていて、意外とスクリプト言語で書く需要があるんじゃないかと思います。
RubyKaigi takeout を経て、 Observability of Ruby, by Ruby, for Ruby の掛け声で、Rubyで書けるRubyのパフォーマンス測定ツール群（もちろん他のプログラムもトレースできるでしょう...）を Infrared.rb というプロジェクトで始めることにしました。このブログでもまたいろいろと紹介できればと思います。
