stefafafan の fa は3つです

"すてにゃん" こと id:stefafafan のブログです

ISUCON Go実装のデプロイスクリプトを組むにあたって、アプリケーションのバイナリ名やデーモンのサービス名を機械的に取得する

ISUCONのデプロイスクリプトを組むにあたって、なるべく一撃でデプロイできるように準備したい。そう思った時に、Goのアプリケーションをビルドする際のバイナリ名やsystemdで動いているサービスの名前が毎回変わっていることを思い出したのでそこも機械的に判定できるといいな、と思って試行錯誤してみました。

アプリケーションの場所を見つける

webapp というディレクトリの中に各言語のアプリケーション実装が配置されているというのがいつもの流れですが、大体 /home/isucon/webapp にあると思いきや catatsuy/private-isu の場合は /home/isucon/private_isu/webapp にあって、微妙に配置場所が変わることもあるかもしれません。

findコマンドを使って webapp ディレクトリを見つけるというのをまずやっておきます。

$ find /home/isucon -maxdepth 3 -type d -name "webapp*"
/home/isucon/webapp

その上で言語の名前のディレクトリが来ますが、Goの場合は go という名前だったり golang という名前であることがあります。

ビルドの際はこの両方のディレクトリを念の為試しておくと安心できます。

$ cd webapp/golang 2>/dev/null || cd webapp/go 2>/dev/null || exit 1;
$ pwd
/home/isucon/webapp/go

サービス名を特定する

例年のISUCONではsystemdを使って各言語の実装が動いていて、サービス名には isugo のように言語名が含まれているがちです。

  • ISUCON14の場合は isuride-go.service

この前提を元にサービス名を特定することができます。

systemctl list-unit-files を実行するとユニットファイルの一覧を取得できるので、その中で isugogrep しつつ、 enabled という文字列が邪魔なので削るとサービス名だけを抽出できます。

$ systemctl list-unit-files | grep 'isu' | grep 'go'
isuride-go.service                             enabled         enabled
$ systemctl list-unit-files | grep 'isu' | grep 'go' | awk '{print $1}'
isuride-go.service

go build 時のバイナリの名前を特定する

アプリケーションをビルドする際、ISUCONの回ごとにバイナリの名前が違うものになっているがちです。

  • ISUCON14の場合は isuride

go build -o isuride-o の引数をどうすればいいのかを探りましょう。

ISUCONでは systemd を使ってサービスのデーモン化をしているので、ユニットファイルの中身を確認することで実行しているバイナリが何かを特定することができます。

systemctl cat コマンドを使うとユニットファイルの中身を出力できます。

$ systemctl cat isuride-go.service
# /etc/systemd/system/isuride-go.service
[Unit]
Description=isuride-go
After=syslog.target
After=mysql.service
Requires=mysql.service

[Service]
WorkingDirectory=/home/isucon/webapp/go
EnvironmentFile=/home/isucon/env.sh

User=isucon
Group=isucon
ExecStart=/home/isucon/webapp/go/isuride
ExecStop=/bin/kill -s QUIT $MAINPID

Restart=on-failure
RestartSec=5

[Install]
WantedBy=multi-user.target

ExecStart に実行しているバイナリが指定されているのでここの最後の isuride を抽出すれば完成です。

$ systemctl cat isuride-go.service | grep ExecStart
ExecStart=/home/isucon/webapp/go/isuride

$ systemctl cat isuride-go.service | grep ExecStart | sed -E 's|.*/([^/ ]+).*|\1|'
isuride

Makefile の中ですべてを組み合わせる

ここまでわかってきたことを組み合わせることで、ISUCONの回ごとにMakefileをカスタマイズしなくとも同じ設定でwebappの中身をデプロイできるようになります(多分)。
前提: このデプロイ方式は手元のwebappの内容をrsyncでpushしています。

deploy-webapp:
	@for server in $(SERVERS); do \
		WEBAPP_DIR=$$(ssh $$server 'find /home/isucon -maxdepth 3 -type d -name "webapp*" | head -n 1'); \
		rsync -avz ./webapp/ $$server:$$WEBAPP_DIR; \
		GO_SERVICE=$$(ssh $$server "systemctl list-unit-files | grep 'isu' | grep 'go' | awk '{print \$$1}'"); \
		BUILD_OUTPUT=$$(ssh $$server "systemctl cat $$GO_SERVICE | grep ExecStart | sed -E 's|.*/([^/ ]+).*|\1|'"); \
		ssh $$server "cd $$WEBAPP_DIR/go 2>/dev/null || cd $$WEBAPP_DIR/golang 2>/dev/null || exit 1; go build -o $$BUILD_OUTPUT"; \
		ssh $$server "sudo systemctl restart $$GO_SERVICE"; \
		ssh $$server "sudo systemctl status $$GO_SERVICE"; \
	done

そのほか: ssh越しだと go コマンドが見つからない

private-isu や ISUCON14 でsshごしに go build を実行しようとしてもコマンドが見つからないというエラーになりました。

サーバ上で which go を実行するとどうやら /usr/bin/go ではない場所のバイナリを使っていることがわかりました。

$ which go
/home/isucon/local/golang/bin/go

PATHを通すなどすると解消される気がしますが、改めて最新のGoを入れ直すのもありかと思い、以下の手順を元に毎回最新のGoを入れ直すことにしています。

go.dev

ISUCONの素振りとして private-isu をPHP実装で解いてみた (約50万点まで)

先日はISUCON14に参加しましたが*1、その直前まで素振りがてら catatsuy/private-isuPHPで解いていました。普段ISUCONはGo言語で参加していますが、他言語での挑戦にも興味がでてきたため、PHPでやってみることにしました。

実際のコードと作業ログは以下のリポジトリにまとめてありますので、これから試してみたいという方の参考になればとても嬉しいです。


前提

private-isu の執筆時点のREADMEに記載されている「推奨インスタンスタイプ」のインスタンスを競技用とベンチマーカー用で1台ずつ建てています ( c7a.largec7a.xlarge )。

github.com

以前Go実装で挑戦したことがありますが、この時のインスタンスタイプは c6i.largec6i.xlarge だったようなので、点数について単純比較はできなさそうです。

blog.stenyan.jp

デプロイ

今回は rsyncwebapp/php ディレクトリを丸ごとデプロイするという方式を取りました*2

GitHubにあげているコードは .gitignorevendor 含めているので、GitHubからpullしてアプリケーションを動かしたい場合は毎回 composer install が必要になります。 rsync でデプロイする場合は手元の環境で既に composer install が済んでいればあとは丸ごとデプロイするだけなのが今回の利点でした。

Makefileに以下のコードを記載することで、 make deploy-app を実行するだけでアプリケーションをデプロイできるようにしました。

deploy-app:
	rsync -av webapp/php/ isu01:~/private_isu/webapp/php/

プロファイリング

今回は tkuchiki/alppt-query-digest で遅いエンドポイントや遅いクエリを分析しました。

その上でアプリケーションのボトルネックをさらに分析するために、Go言語でISUCONに挑戦する際に活用してきた pprof による Flamegraph を利用したアプリケーションの負荷の可視化と同じようなものが使いたくなり、調査しました。

参考にした資料一覧:

はじめは xhprof を使う方式を検討して少し試していましたが、最終的に Reli を使うことにしました。

Reliの利点はアプリケーションコードに手を入れずに使えることです。Go言語のpprofを使う場合は毎回アプリケーションコードに手を入れていたことを考えると、Reliはあまりにも便利で驚きました。おすすめします。

private-isu で Reli を使う

簡単に private-isu で Reli を使って FlameGraph を出力する方法を紹介します。

まずはインスタンスにReliを入れます。

composer create-project reliforp/reli-prof
cd reli-prof

動いているプロセスの名前を確認しておきます。

$ ps auxfw | grep fpm
root         594  0.0  0.6 209068 23900 ?        Ss   11:31   0:00 php-fpm: master process (/etc/php/8.3/fpm/php-fpm.conf)
isucon      2071  0.1  0.4 209632 19228 ?        S    11:49   0:00  \_ php-fpm: pool www
isucon      2150  0.0  0.4 209632 19332 ?        S    11:49   0:00  \_ php-fpm: pool www
isucon      2181  0.0  0.4 209632 18792 ?        S    11:50   0:00  \_ php-fpm: pool www
isucon      2214  0.0  0.0   7076  2176 pts/0    S+   11:51   0:00              \_ grep fpm

i:daemon というサブコマンドを利用して、ベンチ実行中にトレースを取得します。結果をファイルに保存しておきます。

sudo ./reli i:daemon -P "php-fpm" > traces.log

ベンチマークの実行が終わったら c:flamegraph サブコマンドを利用してFlameGraph形式の結果をsvgファイルに書き出します。

./reli c:flamegraph < traces.log > traces.svg

最後にローカル環境にsvgファイルをダウンロードしてブラウザで開いてみると、FlameGraphが表示されます。

rsync isu01:~/reli-prof/traces.svg ./
FlameGraphの様子

設定ファイルの確認・アプリケーションエラーログの出力

private-isu のマニュアルでは nginx と php8.3-fpm.service のログを確認することが案内されています。

php-fpmの設定については、/etc/php/8.3/fpm/以下にあります。

エラーなどの出力については、

$ sudo journalctl -f -u php8.3-fpm
$ sudo tail -f /var/log/nginx/error.log

などで見ることができます。

private-isu/manual.md at 6de65501fa86f0cca01ac70ac3be18ce65703bd3 · catatsuy/private-isu · GitHub

実際触っていると php8.3-fpm.service をみていても正直ほしい情報はそんなに流れてこなくて、基本 nginx のエラーログをみて判断する感じになります。

php.ini にエラーログの設定を追加することによって、アプリケーションのエラーログを書き出すことができるようになります。
php.ini の場所はアプリケーション中(例えばトップページを表示するロジックの中で) phpinfo(); を一時的に追加しブラウザから確認しました。

private-isuの場合、PHP 8.3 向けの FPM の設定ファイルは /etc/php/8.3/fpm/php.ini にありました。設定ファイル内に error_logコメントアウトされていました。デフォルトではエラーログの出力先は空なので、お好きなパスを指定してあげます。

; Log errors to specified file. PHP's default behavior is to leave this value
; empty.
; https://php.net/error-log
; Example:
- ;error_log = php_errors.log
+ error_log = /var/log/php_errors.log

ファイルを一応作っておきます。

sudo touch /var/log/php_errors.log
sudo chmod 664 /var/log/php_errors.log
sudo chown isucon:isucon /var/log/php_errors.log

systemctlの再起動をして反映します。

sudo systemctl daemon-reload
sudo systemctl restart php8.3-fpm.service

これでエラーが起きた際に指定したファイルにアプリケーションのログが出力されるようになります。

sudo tail -f /var/log/php_errors.log

PDO::ATTR_PERSISTENT や composer autoloader optimize の設定

PHP (PDO) でデータベースの接続をプールして使い回すには PDO::ATTR_PERSISTENT を設定する必要があります。

    return new PDO(
        "mysql:dbname={$config['db']['database']};host={$config['db']['host']};port={$config['db']['port']};charset=utf8mb4",
        $config['db']['username'],
-        $config['db']['password']
+        $config['db']['password'],
+        array(PDO::ATTR_PERSISTENT => true)
    );

また、 composer の autoloader に対しても最適化をするための設定があるようです。 以下のように "optimize-autoloader": true,composer.json に追加しておくと良いでしょう。

{
+   "optimize-autoloader": true,
    "require": {
        "slim/slim": "^4.7",
        ...
    }
}

composerのサイトを見に行くとトレードオフは基本的になく、本番環境では有効化しておくことをおすすめされているのでISUCONでもとりあえずやっておくのは良いと思います。

There are no real trade-offs with this method. It should always be enabled in production.

Autoloader optimization - Composer

JITの有効化

PHP 8.0 からはJITコンパイラを有効化することでパフォーマンス向上を見込めます。

phpinfo() の出力結果をみると、 JITの設定は opcache の中にあるようで、 opcache は別途設定ファイルがあるようです。

PHP 8.3の場合は /etc/php/8.3/mods-available/opcache.ini に設定ファイルがあったので、以下のような設定を追加しJITを有効化しました。

; configuration for php opcache module
; priority=10
zend_extension=opcache.so
+ opcache.enable_cli=1
+ opcache.jit=on
+ opcache.jit_buffer_size=100M

詳しくはこちら:

www.php.net

PHP 8.4へのバージョンアップ

PHP-FPMを扱ったままPHPのバージョンをアップグレードすることもできました。

参考: PHP 8.4 Installation and Upgrade guide for Ubuntu and Debian • PHP.Watch

バージョンの上げ方としては、各種パッケージをインストールし、

sudo LC_ALL=C.UTF-8 add-apt-repository ppa:ondrej/php
sudo apt update
sudo apt install php8.4-cli php8.4-fpm php8.4-mysql

php8.3-fpm を停止、 php8.4-fpm を有効化する、

sudo systemctl stop php8.3-fpm.service
sudo systemctl disable php8.3-fpm.service
sudo systemctl start php8.4-fpm.service
sudo systemctl enable php8.4-fpm.service

FPMのプールの設定が /etc/php/8.3/fpm/pool.d/www.conf にあったので 8.3 と 8.4 の差分を確認して揃えます。

- user = www-data
- group = www-data
+ user = isucon
+ group = isucon
...
- listen = /run/php/php8.4-fpm.sock
+ listen = 127.0.0.1:9000

再起動します。

sudo systemctl restart php8.4-fpm.service
sudo systemctl restart nginx.service

nginxの設定がlocalhostの9000番に向いているままであれば設定をいじらなくてもそのままPHP 8.4の状態でつながります。

Unix domain socket を使うように変更したい場合はこの www.conf の設定と nginx の設定を合わせて変更する必要がありました。

github.com

PHP-FPMを捨ててRoadRunnerへ (移行失敗)

徐々にPHP-FPMがボトルネックになっていることに気づき、以下のスライドを参考にRoadRunnerへの移行を試みました。

結論としては結構大変で諦めてしまいました。その代わり、RoadRunnerへ移行するために必要な手順を理解することができました。

  • RoadRunnerの設定ファイル (rr.yaml) の追加
  • RoadRunner向けworkerファイルの追加 (worker.php)
  • workerファイルから既存のDI ContainerやRoutesの設定をハンドリングできるようにコードを調整
  • Ubuntu上にRoadRunnerをインストールし、systemd向けのユニットファイルを定義 (デーモン化)
  • PHP-FPMデーモンの停止・無効化。RoadRunnerの起動・有効化
  • nginxの設定で既存のFastCGIからRoadRunnerの設定を参照するように変更

ブラウザ上で "なんとなくprivate-isuが動く" 状態にできましたが、よくよく見てみると画像アップロード周りで壊れていたり、複数workerに対応できなかったりしてベンチマーカーがエラーを返してしまいました。以下のPull Requestが試していた様子となります。


点数遷移

細かいFlameGraphの様子などは以下のドキュメントにまとめていますが、ここでもざっとやった改善と点数の推移を記載します。

github.com

以下みていくと、ISUCON本*3でも紹介されている改善を愚直にやると点数がどんどんあがっていって、PHPっぽい改善で効果を感じたのは「PDO::ATTR_PERSISTENTの設定」くらいでした。PHPバージョンアップやJIT有効化を実施してみたものの、他の部分がボトルネックになっていたのであまり効果は感じられなかったのかもしれません(RoadRunner移行が達成できれば更なる点数の上昇は期待できたと思います)。

実施内容 点数
初回ベンチマーク (Ruby実装) 1026
PHP実装に切り替え 3288
各種計測ログや計測を仕込んだ後 2802
commentsテーブルへindex追加 27353
ユーザの画像をnginxから配信 57835
トップページから呼んでいるクエリの全件取得をやめる + ORDER BY狙いINDEX追加 93054
他のmake_posts周辺クエリも同様に改善する 112481
make_posts内のpostのuserを引いてくるクエリをなくす 124309
make_posts内のcomment_countのN+1改善 141431
MySQLのbinlog無効化 153314
make_posts内のcommentsのN+1解消 188721
make_posts内の最後のN+1解消 226115
外部コマンド呼び出しをやめる 257402
comments.user_id へのINDEX追加 272468
INDEXの追加とFORCE INDEXの指定 326587
MySQLの設定チューニング 320129
静的ファイルをnginxから配信 323388
nginxのworker_connections増やしたりgzipの設定を追加したり 322611
ベンチマーカーインスタンスのファイルディスクリプタを増やす 327821
opcache.jit 有効化 329357
PHP 8.4 へバージョンアップ (&& reliプロファイラ実行をやめる) 438270
PHP 8.4でもJIT有効化を試みる 433228
PHP 8.3に戻してプロファイラ実行せずにベンチ回してみる 431496
PHP 8.3に戻してプロファイラを再び実行する 344578
PDO::ATTR_PERSISTENT を設定する 371402
composer autoloader optimize 設定する 370456
Unix domain socket を使うようにする 377267
各種パラメータ調整、PHP8.4に戻す、ログを無効化 533117
MySQL 8.0 → 8.4 へアップグレード 502465
MySQL 8.4 → 9.1 へアップグレード 498680

感想

素振りを進める中で思ったこととしては、結局プログラミング言語として何を選んだとしても大きな影響はなさそうということです。昨今ISUCONにGo言語で挑戦する人が多いですが(私含め)、ボトルネックはデータベースやアプリケーションロジックがメインなので、手に馴染んだ言語で挑戦するのが良さそうだなと改めて気付かされました。

与えられた時間が無制限にある場合Go言語は最終的にテンプレートの生成がボトルネックになっていくのをprivate-isuに前回挑んだ時に感じましたが、PHPの場合はPDOのコンストラクタを作るところに行き着く(なのでPHP-FPMをやめよう)という部分に言語特有の違いが感じられて面白かったです。ただ、ISUCON当日にここまでたどり着く時間的余裕はなかなかなさそうなのでそんなに「PHP-FPMからの移行の素振り」とかは気にしなくてもいいかもと思ったりしました。

アプリケーションの負荷やエラーログの確認方法はエンバグしたときのデバッグに不可欠な要素なので、その点だけしっかりと見直しておけると良いと思います。

ISUCON14 に参加した (5259点くらい) #isucon

今年も参加しました。いつもありがとうございます!
isucon.net


これまでの

分担

  • うちのチームはこれといった決まった分担はなく、初動だけ誰が環境をセットアップして誰が計測ツール入れてという割り振りは決めていますが、それ以降は作戦会議しつつやっています
  • 今年は大きく3つほど取り組んだことがあって、こういう感じになりました:
    • stefafafan: chair_locationsテーブルのクエリをなんとかする。その他細かい改善
    • papix: マッチングアルゴリズム見たり、他メンバーの壁打ち
    • masawada: 通知のServer Sent Eventsのやつを見たり

自分目線でどうだったか

  • 初動はまぁまぁ悪くはなかった、11時の時点でベンチも回し済みでコードもGitHubにプッシュしていて計測結果も出ていてMySQLの負荷が高いことはわかっていた。手でアプリケーションの動作確認も軽く終えていた
  • そのあと取り組むべき課題もわかってよかった
  • ただそれらの課題をやっていくのに手間がかかりすぎていつの間にか終わってしまった..
chair_locationsの件

chair と chair_locations をJOINして距離を出しているクエリあまりにも遅かった (3秒とか) のでなんとかしようとなって、段階的に色々ゴニョゴニョし続けていた..

1. chair_locationsにtotal_distanceカラムを足しつつ、椅子をポストしたタイミングでこのカラムを更新。初期データはpostInitialize時にどうにか更新する
2. 1をやってみた結果、total_distanceの値は明らかにおかしなことになってしまい (本来200とかであるべき距離が2000になっていたり) したので、「前の座標との差分を足し続けるのはなんか実装おかしそう」と気づいて、データの初期化ロジックをどうにかできないか模索
3. 初期データがgzipされた状態であることに気づいてそれを解凍してその中身のchair_locationsをshellscriptを使ってがちゃがちゃやって、chair_locationsそれぞれに距離をカラムとして持てる状態に変更 (chair_locations.total_distanceという名前のままだったけど実体は chair_locations.distance みたいな感じにしました)
4. 3をやった結果重いクエリは若干簡略化できて (JOINは残っているが chair_locations.distance の sum を取るだけで距離がゲットできるようになった)、INDEXも足した結果、このスロークエリの順位が1位から3位くらいに下がった
5. 一旦満足して他のクエリのINDEXを足したりbinlogを無効化するなどした結果、やはりchair_locationsのクエリが再び1位に戻ってきた
6. chair_locations.distanceを合計すればchairのtotal_distanceがわかるなら、chair.total_distanceとchair.total_distance_updated_atをはやしてそれを更新すればええやん、とやり始めて、大体動いたのでベンチを回したらなぜか sql no rows が出るようになり、「え、ErrNoRowsのハンドリング漏れているところなくね?」となってあちこち眺めている間に時間切れになり、根本的なクエリの改修を入れられなかった..

sql.ErrNoRows の解消ができないまま終わるなんて、という感じでつらみがありました。DB分割ももちろんやれず1台で終わり。

他メンバー

マッチングアルゴリズムと通知でめちゃくちゃハマっていそうでした。これらの内容もうまく入れられずに終了しました。

感想

他2人が苦戦している間に自分が適当なINDEX追加などをやっておいた結果5000点くらいにはなったのはよかったけど「やってやったぜ」みたいな改善はチームとして入れられずに終わり、つらみ。プロファイラの無効化も忘れていたし再起動試験通るのだろうか..

以前はチームメンバーみんなで素振りをなんどもやっていましたが、今年はみんなやや忙しく、1度もがっつりとした素振りはできなかった(前日に初動の動き方認識合わせのみやった)ので、普通に練習不足という感じでした。

大会として

毎回反省ポイントがあってつらくはなっているもののISUCON自体はとても楽しいイベントで今年も開催されて本当に嬉しかったです!ありがとうございました!!

今回題材のWebアプリケーションも触っていて出来がすごくよくてびっくりしました。フロントエンドもちゃんとReact (Remix Framework) 使っているんだな〜と思ったりしました。おつかれさまでした。

nginxのアクセスログを解析してJSONを返すだけのCLIをRustで作成した

最近RustでCLIを作るのに突然ハマってきたのと、ISUCON が近づいていることもあって、以下のCLIを作ってみました。

github.com

使い方

現状はnginxのlog_formatをJSONとした上で特定のキーを持っていることを想定しています。 (こういう感じの設定をしておく👇)

log_format json escape=json '{'
                            '"time":"$time_iso8601",'
                            '"host":"$remote_addr",'
                            '"method":"$request_method",'
                            '"uri":"$request_uri",'
                            '"status":"$status",'
                            '"body_bytes":"$body_bytes_sent",'
                            '"referer":"$http_referer",'
                            '"ua":"$http_user_agent",'
                            '"request_time":"$request_time",'
                            '"response_time":"$upstream_response_time"'
                            '}';

この状態で吐かれたアクセスログを、 seki にパイプして食わせるのみです。以下のような形のJSONが返ってきます。*1

$ cat access.log | seki
[
  {
    "method": "GET",
    "uri": "/hello",
    "count": 1,
    "status_code": {
      "status_1xx": 0,
      "status_2xx": 0,
      "status_3xx": 1,
      "status_4xx": 0,
      "status_5xx": 0
    },
    "response_time": {
      "min": 0.0,
      "max": 0.113,
      "avg": 0.113,
      "sum": 0.113,
      "p50": 0.113,
      "p75": 0.113,
      "p90": 0.113,
      "p95": 0.113,
      "p99": 0.113
    }
  }
]

このJSONをどう使うかはユーザに委ねる、という感じです。

思想

tkuchiki/alpmatsuu/kataribe など便利ツールが世の中にあるので新たに作る必要は特にないですが*2、思想としてはJSONとして返しておけば色々と加工したり独自のスクリプトに組み込んであれこれしやすそうではないか?と思って作ってみています。

そのため、 seki 自体が人間にみやすいフォーマットへの出力オプションを持つ予定はないです。

private-isu でちょっと使ってみた様子

実際に catatsuy/private-isu でも使ってみました。AMIを利用してEC2サーバを建てた上で実施しています。

まず seki をインストールします。今回は Release v0.1.2 · stefafafan/seki · GitHub に載っている curl を使う手順を使います。

$ curl --proto '=https' --tlsv1.2 -LsSf https://github.com/stefafafan/seki/releases/download/v0.1.2/seki-installer.sh | sh

PATHを通したかったら source してねと言われるのでします。

$ source $HOME/.cargo/env

nginx.conf の log_format を書き換えた上でベンチマークを回します。終わったら早速 seki を使ってみます。

$ sudo cat /var/log/nginx/access.log | seki

これを何気なく実行すると結果が長すぎることがわかります。 /posts/12667 みたいなエンドポイントが沢山個別にならんでいるのでグルーピングします。

一旦エンドポイントの一覧をざっとみてみましょう。 jq コマンドで .uri のみ抽出します。

$ sudo cat /var/log/nginx/access.log | seki | jq '.[] | .uri'
"/posts/12667"
"/posts/2005"
"/image/6908.jpg"
"/image/9785.jpg"
"/image/9228.jpg"
"/posts/556"
"/posts/4366"
"/image/1149.jpg"
"/posts/7523"
"/posts/5208"
"/posts/1797"
"/posts/3376"
"/@lindsay"
"/@violet"
"/image/1855.jpg"
"/image/6059.jpg"
"/posts/7627"
...

/posts/\d+/images/.+/@[a-zA-Z0-9]+ みたいなのが沢山ありそうですね。 config.toml にグルーピングの設定を書きましょう。 リポジトリにもサンプルがあります。*3
github.com

$ vim config.toml
$ cat config.toml
[[grouping]]
regexp = '^/posts/\d+$'

[[grouping]]
regexp = '^/@[a-zA-Z0-9]+$'
name = '/@:username'

[[grouping]]
regexp = '^/image/.+'

regexp正規表現を書きます。 name の指定はオプショナルですが、名前をつけたいときに書いておくとURLが並んだ時に見やすくなります。

今一度先ほどのコマンドを実行してみます。 seki は同じ階層にある config.toml をデフォルトで読み込みますが、 --config で明示的にパスを指定することもできます。

$ sudo cat /var/log/nginx/access.log | seki | jq '.[] | .uri'
"/login"
"/posts"
"/"
"/@:username"
"/admin/banned"
"/image/.+"
"/comment"
"/initialize"
"/js/main.js"
"/register"
"/"
"/css/style.css"
"^/posts/\\d+$"
"/favicon.ico"
"/login"
"/js/timeago.min.js"
"/logout"

いい感じにグルーピングができたので、あとは好きな形に加工してベンチの結果を確認してみましょう。今回は response_time.sum 順にしつつ、 column コマンドで整形して出力してみます。

$ sudo cat /var/log/nginx/access.log | seki | \
    jq -r "sort_by(-.response_time.sum) | \
        .[] | \
        [.method, \
        .uri, \
        .status_code.status_2xx, \
        .status_code.status_3xx, \
        .status_code.status_4xx, \
        .status_code.status_5xx, \
        .response_time.sum] | \
        @tsv" | column -t
GET   /                   3939  0      0    0  198.79800000000128
GET   /posts              1590  0      0    0  95.20300000000013
GET   ^/posts/\\d+$       2829  0      0    0  93.72100000000103
POST  /login              0     1872   0    0  78.4420000000002
GET   /@:username         482   0      0    0  40.025
GET   /login              694   0      0    0  19.445999999999984
POST  /                   0     162    162  0  17.529000000000003
GET   /image/.+           2977  90691  0    0  16.31000000000001
POST  /register           0     263    0    0  12.548999999999992
GET   /logout             0     347    0    0  9.674999999999988
POST  /comment            0     244    0    0  7.659999999999998
GET   /admin/banned       0     0      263  0  7.20899999999999
GET   /initialize         1     0      0    0  0.369
GET   /css/style.css      5504  0      0    0  0.0
GET   /js/timeago.min.js  5504  0      0    0  0.0
GET   /favicon.ico        5504  0      0    0  0.0
GET   /js/main.js         5504  0      0    0  0.0

GET / が遅そうなので、ここの改善をしていきましょう。

作ってみての感想

当初思っていたよりもサクッとCLIが作れてよかった、 閉包テーブルによる階層構造をPlantUMLやMermaid形式で可視化するツールを作った - stefafafan の fa は3つです の時と同様に clap-rs/clap がやっぱり便利なのと、それ以外にも各種バイナリの用意やリリースのためのツール群 (crate-ci/cargo-releaseaxodotdev/cargo-dist) もとても助かりました。

そして実装の際に alp のこと改めて調べていましたが、めちゃくちゃ機能充実していてすごいなと思ったりしました。実装にあたってalpとkataribeのインターフェースはとても参考にしました、ありがとうございます🙏 複雑なjqのクエリを書くのは大変なのでこれら既存のツールを使うのが一番手っ取り早いなと改めて思いました(が自分でも作るのは楽しかったです)。

次は pt-query-digest 代わりのCLIも作りたいです (?)。

*1:もっとこういうJSONのインターフェースにしてほしいみたいなのがあったらいつでもissueなりでコメントお待ちしています!

*2:自分でも作ってみたかったので作ったのが大きい

*3:設定ファイルのフォーマットは kataribe と同じような形式を採用しています🙏

閉包テーブルによる階層構造をPlantUMLやMermaid形式で可視化するツールを作った

最近仕事で触っているサービスが階層構造を扱っていて、それが閉包テーブル (Closure Table) というパターンで実現されていますが、「結局(視覚的に)どういう構造になっているの?」というのがパッとみれたらいいなと思うことがあり、簡単なツールを作ってみることにしました。

できたものはこれです。

github.com

前提: 閉包テーブル (Closure Table) とは

閉包テーブルとは、「SQLアンチパターン」という書籍で紹介されているパターンです。階層的なデータ (例えばSNSのスレッド) をRDBで素朴にモデリングしようとすると、「あるスレッド内に存在するコメント一覧」をまとめてクエリしたくなったとしても、スレッドが無制限に続いたり途中で枝分かれしはじめるとクエリを書くのが大変になっていきます。

実際のデータが含まれているテーブルとは別に、階層関係を持つ「閉包テーブル」というテーブルをわけて持たせるようにすると簡単なクエリで目当てのデータが取得できるようになります。

本書では以下のようなテーブルを紹介しています。 TreePaths テーブルに祖先と子孫のIDを持つカラムがあり、これによってあるコメントに紐づく子孫一覧などが簡単に取得できるようになります。

-- ※ 簡略化しています
CREATE TABLE Comments (
    comment_id, 
    ...
);

CREATE TABLE TreePaths (
    ancestor,   -- 祖先
    descendant, -- 子孫
);

実際に TreePaths テーブルに含まれるデータの例:

ancestor descendant 解説
1 1 最も親となるコメント。自分への参照も持つので、ancestor=descendant
1 2 1→2という関係
1 3 1→3という関係 (直属の子ではなく、孫の関係であっても閉包テーブルとしては持つ)
1 4 ↑と同様
2 2 2つめのコメント
2 3 2→3という関係
2 4 2→4という関係
3 3 3つめのコメント
4 4 4つめのコメント

上記でポイントとなるのは、 1→2→31→2→4 という親子関係になっている場合において、2を飛ばして 1→31→4 の関係も持たせている点です。これによって、 ancestor=1 のデータをクエリするだけで、親もしくは先祖に1がいるコメントを全件取得したり、逆に descendant=4 でクエリすれば4を子もしくは子孫に持つコメントを全件取得できるようになっています。

行一覧を見ても、実際の構造がどうなっているのかよくわからない

先ほどの例で出した表をパッとみても、個人的には結局どういう階層構造になっているのかがいまいちわかりづらいと思いました。頭の中で図を描いていくと最終的にはわかりますが、1階層ずつたどる必要があって地味に難しいです。

途中で行が増減したり子が付け変わったりした場合に、閉包テーブルでは大きく行数が変動するので差分も若干わかりづらい気がします。ということで表題の話になりました(あと、単純にRustでCLIツールを何か作れたら面白そうというモチベーションもありました)。

木構造の可視化

あまり自分でグラフの描画を実装する気持ちになれなかったので、描画部分はPlantUMLやMermaidに任せることにしました。なので、閉包テーブルのデータをPlantUMLなどの別フォーマットに変換するだけのCLIツールを作ることにしました。

PlantUMLのサイトを見たところ、WBS図が一番木に近かったので、これに変換することにしました。

plantuml.com

アスタリスクの数が多ければ階層が深い、みたいな雰囲気です。

@startwbs
* A
** B
*** D
** C
*** E
@endwbs

Mermaidについてはフローチャートを使うことにしました。
mermaid.js.org

PlantUMLと違って、Mermaidのフローチャートは階層を表していないので、自分でいい感じに表す必要があります。

flowchart TD
    A --> B
    B --> D
    A --> C
    C --> E

余談ですが、木構造専用の記法を追加してほしいというissueがMermaidのリポジトリに立っていることを調べていてたまたま発見しました。

github.com

作成したツールの使い方

github.com

JSON形式で閉包テーブルを渡すことを想定しています。また現状 ancestor descendant depth の三つのkeyを持つオブジェクトの配列を想定して作ってあります。

以下のような input.json というファイルが手元にあるとして、

[
	{
		"ancestor": "A",
		"descendant": "A",
		"depth": 0
	},
	{
		"ancestor": "A",
		"descendant": "B",
		"depth": 1
	},
	{
		"ancestor": "A",
		"descendant": "C",
		"depth": 1
	},
	{
		"ancestor": "A",
		"descendant": "D",
		"depth": 2
	},
	{
		"ancestor": "A",
		"descendant": "E",
		"depth": 2
	},
	{
		"ancestor": "B",
		"descendant": "B",
		"depth": 0
	},
	{
		"ancestor": "B",
		"descendant": "D",
		"depth": 1
	},
	{
		"ancestor": "B",
		"descendant": "E",
		"depth": 1
	},
	{
		"ancestor": "C",
		"descendant": "C",
		"depth": 0
	}
]

--format plantuml でコマンドを実行すると、

closure2wbs --input input.json --output out.puml --format plantuml

以下のPlantUML形式のファイルが吐き出されます。

@startwbs
* A
** B
*** D
*** E
** C
@endwbs
PlantUML形式のファイルをプレビューした結果

同じように --format mermaid でコマンドを実行すると、

closure2wbs --input input.json --output out.puml --format mermaid

以下のMermaid形式のファイルが吐き出されます。

flowchart TD
    A --> B
    B --> D
    B --> E
    A --> C
Mermaid形式のファイルをプレビューした結果
実装ロジック

実装ロジックとしては、以下のような流れになっています。

  1. パースしたJSONの中から、一番親のノードを探索
  2. 親のノードを出力しつつ、直属の子 (depth=1) も再帰的に出力する

再帰呼び出ししている箇所はこういう感じです。

github.com

Rustについて

最近「Rustの練習帳」を少しだけ読んでいて、その中でRustでCLIツールを作るというのをやっていて、「もしかしたら簡単に作れそうかも」となったのでやってみました。

CLIツールに必要なオプションのパースとかは https://github.com/clap-rs/clap が勝手にやってくれて楽でした。一方でRustっぽい書き方できている自信はなくて、なんならGitHub Copilotがめちゃくちゃ活躍してくれたので、はたして..という感じです。

終わり

RustでちょっとしたCLIツール作るハードルも下がって、成果物も(PlantUMLやMermaidのおかげさまで)視覚的にわかりやすくてよかったです。ちょっとしたCLIツールを作ってみると結構楽しくておすすめします。