小さいほうが、負けました。
50GB では ripgrep と並んでいるのに、3GB では 1.48 倍遅い。ファイルが小さくなるほど成績が落ちる、という妙な形になっていました。
索引を持っているのだから、小さいファイルこそ有利なはずです。何が逆を向かせていたのか。
- 先に結論: 3GB で負けていた原因は検索そのものではなく、1 回ごとに必ず払う固定費でした。.NET の段階的 JIT（TieredCompilationQuickJitForLoops）を切って、ライセンス確認に使っていた外部コマンド ioreg の起動（約 0.2 秒／回）をやめた結果、3GB・メモリに載った状態の検索 7 項目の合計が 11.46 秒 → 7.95 秒（1.44 倍）、uvp の対 ripgrep 比は 1/1.48 → 1.16 になりました。同じ設定を無料版の uvf に入れても 8.33 秒 対 8.23 秒＝1.2% しか動きません（こちらは読み出し律速）。Mac M4・メモリ 32GB・外付け USB SSD・OpenStreetMap XML・2 回目（hot）での測定例。詳細は記事末尾。
- 問題: サイズが小さいほど負ける
- 原因（1）: 最適化の弱いコードで走り終わってしまう
- 原因（2）: 毎回 0.2 秒、外部コマンドを起動していた
- 手当て: 直してから、効かない相手にも同じ設定を入れてみる
- 数字: 3GB の負けが勝ちに変わった
- 持ち帰れる一般論: 「効かないはずの相手」に同じ変更を入れる
- 使っている道具
- リンク
先に結論: 3GB で負けていた原因は検索そのものではなく、1 回ごとに必ず払う固定費でした。.NET の段階的 JIT（TieredCompilationQuickJitForLoops）を切って、ライセンス確認に使っていた外部コマンド ioreg の起動（約 0.2 秒／回）をやめた結果、3GB・メモリに載った状態の検索 7 項目の合計が 11.46 秒 → 7.95 秒（1.44 倍）、uvp の対 ripgrep 比は 1/1.48 → 1.16 になりました。同じ設定を無料版の uvf に入れても 8.33 秒 対 8.23 秒＝1.2% しか動きません（こちらは読み出し律速）。Mac M4・メモリ 32GB・外付け USB SSD・OpenStreetMap XML・2 回目（hot）での測定例。詳細は記事末尾。
この記事は「First Light」連載の第 7 回です。v1.6.6 には「First Light」というペットネームを付けました。画面もコマンドもファイルを 1 回読むだけで開いて探せるようになり、UwView としてひとつ完成した形になった版だからです。今回の固定費の手当ては、その v1.6.6 に入った変更のうち、サイズが小さいほうの端を直したものです。
問題: サイズが小さいほど負ける
有料版のコマンド uvp は、.uwvz（圧縮＋索引）を持っているぶん 2 回目以降が速くなる作りです。50GB では実際にそうなります。ところが 3GB では、こうなっていました。
3GB・メモリに載った状態（hot）・v1.6.3 時点
uvp1.04 秒- ripgrep 0.32 秒
- 比 1/1.48（こちらが 1.48 倍遅い）
1.04 秒と 0.32 秒。体感ではどちらも一瞬で、実務で困る差ではありません。ただ、理屈と逆を向いているのが気持ち悪かった。索引があるなら、探す仕事そのものは小さいファイルほど軽くなるはずです。それなのに比だけが悪化する。
この形が意味するのは 1 つしかありません。時間の中に、ファイルの大きさと無関係な項が混ざっている。 50GB ではそれが全体の 0.4% になって見えなくなり、3GB では効いてくる。つまり探しているのは「遅いアルゴリズム」ではなく、定数です。
問いはこうです。1 回のコマンド実行に必ず付いてくる代金は、いくらで、何に払っているのか。
原因（1）: 最適化の弱いコードで走り終わってしまう
まず .NET の実行の仕組みに当たりました。
.NET の既定は「段階的コンパイル」です。最初は素早くコンパイルできる最適化の弱いコードで動き始め、よく通る場所だと分かった時点で最適化したコードに差し替えます。長時間動くサーバー向けには合理的な設計です。起動が速く、稼働が長くなるほど速いコードの割合が増えます。
ところが短い検索では、差し替えが間に合う前に処理が終わります。3GB を数えて探すループが、最適化前のコードで最後まで走り切ってしまう。長いものほど得をして、短いものほど損をする仕組みなので、症状の形（小さいほど負ける）とぴたり合います。
対策は設定 1 つでした。TieredCompilationQuickJitForLoops=false——ループを含む関数は最初から最適化してコンパイルする。起動が少し重くなる代わりに、短い処理でも本来の速さで走ります。
原因（2）: 毎回 0.2 秒、外部コマンドを起動していた
もう 1 つは、検索とまったく関係のない場所にありました。ライセンス確認です。
有料版は「この機械で使う権利がある」ことを確認します。そのとき、機械を一意に識別する値を取るために macOS の ioreg コマンドを外部プロセスとして起動していました。
外部プロセスの起動は、それ自体が高い。実行ファイルを見つけ、プロセスを作り、動的リンクを済ませ、出力を受け取って、終わるのを待つ。1 回あたり約 0.2 秒。
この 0.2 秒は、検索が 0.3 秒でも 300 秒でも同じだけかかります。まさに探していた定数でした。
やめ方も単純です。同じ値は OS の API から直接読めます。macOS は gethostuuid()、Windows は MachineGuid。外部コマンドを起動せず、関数を呼ぶだけにしました。値が変わってしまうと既存の利用者のライセンスが通らなくなるので、置き換え前後で同じ値が返ることをテストで突き合わせています。
ここで大事なのは、手当ての前に 0.2 秒という見積りが出ていたことです。直したあとの実測がその 0.2 秒ぶんだけ動けば、原因の特定が正しかったと言えます。逆に動かなければ、直したのは別のものです。
手当て: 直してから、効かない相手にも同じ設定を入れてみる
ここがこの回でいちばん書きたかったところです。
JIT の設定は、有料版だけでなく無料版の uvf にも同じように入れました。無料版には .uwvz も並列検索もなく、素直にファイルを 1 回読むだけの作りです。読み出しで律速しているはずなので、CPU 側を速くしても秒数は動かない——という予想が立ちます。
結果はこうでした。
3GB・hot・7 項目の合計
| 設定なし（既定） | 設定あり | 比 | |
|---|---|---|---|
uvp（有料・索引あり） |
11.46 秒 | 7.95 秒 | 1.44 倍 |
uvf（無料・1 回読み） |
8.23 秒 | 8.33 秒 | 1.2%（動かない） |
| ripgrep（対照群） | 7.81 秒 | 7.81 秒 | 不動 |
uvf は動きませんでした。これは失敗ではなく、確認です。 設定が配布物に届いていること自体は、実行時の構成ファイルを開いて別に確かめてあります。届いているのに動かないのだから、「uvf の 3GB 検索は CPU ではなく読み出しで律速している」という読みが裏から支えられたことになります。
そして ripgrep が 7.81 秒から動かないことで、測定そのものがぶれていないことも言えます。同じ機械・同じ時間帯で、片方だけが 1.44 倍動き、他の 2 つは動かない。もしディスクの気分や室温で全体が揺れていたなら、3 つが揃って動くはずです。
もう 1 つ、同じ根から出ていた症状も消えました。10GB で uvp が 2〜3 倍遅くなるという退行が別途報告されていたのですが、これも JIT の設定で解消しています（cold 43.77 → 25.55 秒、hot 29.12 → 11.20 秒）。離れた場所の 2 つの症状が 1 つの設定で消えたという事実が、原因の同一性のいちばん強い証拠になりました。
ついでに直した 1 つ: 走査中に持てる本文の上限
固定費とは別ですが、同じ版で内部の上限も 1 つ動かしています。検索中に手元に置いておける「ヒット行の本文」の上限が 256MB で、超えると出力のときに .uwvz から全行を読み直していました。ヒットが極端に多い検索（50GB の正規表現で 1,153 万件）では、15.0 秒のうち 8 秒がその読み直しでした。上限を 512MB に上げて、この読み直しが起きる条件を遠ざけています。
数字: 3GB の負けが勝ちに変わった
3GB・hot・Mac M4・メモリ 32GB・外付け USB SSD・OpenStreetMap XML
| v1.6.3 時点 | v1.6.6 “First Light” | |
|---|---|---|
uvp 対 ripgrep（hot） |
1/1.48（負け） | 1.16（勝ち） |
7 項目合計（uvp） |
11.46 秒 | 7.95 秒 |
-v（除外検索）単体 |
3.59 秒 | 1.95 秒 |
uvf 対 ripgrep |
ほぼ同等 | ほぼ同等（変化なし） |
判定の書き方を揃えておきます。
- 7 項目の合計 1.44 倍は、合計についての基準（7 項目以上で 1.3 倍未満は差と呼ばない）を超えているので「差」と書きます
-v単体の 1.84 倍は、単項目の基準（1.5 倍未満は差と呼ばない）を超えているので「差」と書きますuvfの 1.2% は、当然どちらの基準にも届きません。「効果なし」と書きます- 1/1.48 → 1.16 は「負けから勝ちに変わった」ですが、1.16 倍そのものは 1.5 倍未満なので「勝った」ではなく「並んだ・わずかに上」が正しい書き方です。この回の成果は「勝った」ことではなく、理屈と逆向きだった形が直ったことです
正直に書いておくこと
- 上の値はすべてメモリに載った状態（hot）の数字です。cold（
sudo purge後）では読み出しが支配的になるため、この改善はほとんど見えません。固定費の改善は、固定費が見える条件でだけ見えます - 3GB の絶対値は 1 秒前後の世界です。実務の待ち時間としては改善前でも十分に速く、この回は体感の改善ではありません
- 2 回計（1 回目と 2 回目の合計）で見ると 3GB の
uvpは 1.75 倍です。1 回目は.uwvzを作るので時間がかかり、hot 単独の比よりよい数字になります。どちらの数え方をしているかを明示せずに比べると、いくらでも都合よく見せられます - 数字は Mac での測定です。Windows・Linux は媒体もキャッシュの作法も違うので、秒数を OS またぎで比べないでください
- 改善直後の計測では対 ripgrep 比を 1.17 と記録しており、到達点として整理した表では 1.16 です。0.01 の違いは測定のばらつきの範囲で、どちらかが誤りという意味ではありません
持ち帰れる一般論: 「効かないはずの相手」に同じ変更を入れる
性能の改善で困るのは、効いたように見えて効いていないときです。測るたびに数字は動くので、1 つの数字が良くなっただけでは何も言えません。
このとき役に立つのが、効かないと予測できる相手を用意しておくことです。今回は 3 つ並べました。
- 直した本体（
uvp）——効くはず - 同じ変更を入れた、律速の違う兄弟（
uvf）——効かないはず - まったく手を触れていない他人（ripgrep）——動かないはず
1 だけが動いて 2 と 3 が動かなければ、「効いた」と言えます。3 つ揃って動いたなら、環境が揺れただけです。2 が動いてしまったなら、律速の理解が間違っています。予測を外側に置いてから測ると、数字がどう出ても何かが分かる形になります。
もう 1 つ。サイズを変えて測ると、時間の内訳が分解されます。 固定費は小さい入力で、比例費は大きい入力で見えます。「大きいファイルでちゃんと速いのに小さいファイルで負ける」は、性能のバグではなく固定費が見える条件になったというだけの話です。逆向きに「小さいときだけ速い」なら、比例費のどこかに無駄があります。
最後に、いちばん素朴な教訓を。今回いちばん効いた 1 行は、設定ファイルの 1 行でした。 そして次に効いたのは、検索ロジックではなくライセンス確認から外部コマンドを取り除いたことです。速さの問題が、速さのコードの中にあるとは限りません。1 回の実行に付いてくる儀式——認証、設定の読み込み、バージョン確認、外部プロセスの呼び出し——を数えるほうが、たいてい先です。
使っている道具
UwView は巨大テキスト・巨大ログのビューアです（無料版 UwView／有料版 UwView Pro）。
コマンドラインから同じことをする
# 2章: 3GB くらいのファイルを2回続けて聞く（2回目が速い）
uvp app.log 'ERROR'
uvp app.log 'timeout'
# 4章: 除外検索（この回で 3.59秒 → 1.95秒 になった項目）
uvp app.log 'ERROR' -E 'health|ping'
# 4章: 大小無視・正規表現
uvp app.log 'error' -i
uvp app.log -E 'timeout|refused'
# 5章: 2語で絞り込む（1語目の結果の中から2語目を探す）
uvp app.log 'ERROR' 'payment'
# 5章: 結果をファイルへ
uvp app.log 'FATAL' -out fatal.txt
終了コードは grep と同じで、0＝あり・1＝なし・2＝エラーまたは結果が不完全。if uvp app.log 'FATAL'; then がそのまま書けます。
正直に書くと、1 問目は uvp が ripgrep より少し遅くなります——.uwvz（圧縮＋索引）を先に作るぶんで、50GB なら 59.0 秒 対 54.9〜55.8 秒＝6〜7%（v1.6.6.1）。効いてくるのは 2 問目からで、同じ 50GB の検索が 6.56 秒、ripgrep に対して 8.4 倍速くなります。3GB のような小さいファイルでは同等——索引を引く意味が薄くなります。無料の uvf は、どのサイズでも ripgrep と同等です（実測記事。Mac M4・メモリ 32GB・外付け USB SSD・OpenStreetMap XML での測定例で、環境により異なります）。
リンク
- 第 1 回: 「速さの道具ではありません」と書いた日の内訳: https://uvp.y42u.net/blog/uwview-fl01-v160-confession/
- 第 2 回: 2 回半読んでいた CLI を 1 回にする: https://uvp.y42u.net/blog/uwview-fl02-one-pass-rawgrep/
- 第 5 回: 件数が揺れた話（CLI の仕様を決める）: https://uvp.y42u.net/blog/uwview-fl05-deterministic-count/
- 3GB で ripgrep に追いついた時点の実測: https://uvp.y42u.net/blog/uvp-beat-rg-at-3gb/
- 81 項目を ripgrep・sed と 1 行ずつ突き合わせた話: https://uvp.y42u.net/blog/uvp-vs-ripgrep-sed-81-checks/
- ソースコード（GitHub）: https://github.com/amru195704/UwView
そして、ストレージを専有している巨大ログを圧縮して保管し、さらに高速に検索したいなら UwView Pro をどうぞ。永続索引・圧縮キャッシュ検索・約 1/9 保管で、開き直しも検索も一段速くなります（全 OS 対応・買い切り／月額プランあり）。
開発者より: アプリ・Kindle 本・公開プロジェクトの一覧は GitHub: amru195704 にまとめています。
