15 本のゲートが全部緑で、どれも訊いていなかった問い

コンテナ基盤の記事を公開した 3 日後、やり残しを探した。全テストが避けていた既定のディスク、説明できないので「報告」にしておいた数字、カーネルに訊かないまま「意味が成立しない」と書いた能力、オプションを 1 つ書き足したらコマンドが 2 つ消えたヘルプ。4 つとも、すぐ隣に検査があって、その検査は他の検査と一致していた。

merecontainerstestingverificationsystemsdogfood

3 日前、自作言語で書いたコンテナ基盤 —— VMM、Docker Engine API を喋るデーモン、OCI ランタイム、レジストリ —— について書き、最後を「実際に使って初めて出たバグ」という節で締めた。 そのあと戻って、退屈な問いを自分に訊いた: やり残しはあるか?

4 つあった。まとめて書きたいのは、4 つとも同じ形をしているからで、 その形は「テストを書き忘れた」ではない。どれも、すぐ隣に検査があった。 検査は緑だった。そして全部が、少しだけ簡単な問いに静かに合意していた。

以前、ガードレールは 1 つのプログラムを守り、ゲートは問いを守る と書いた。これはその文の裏側にある失敗の形だ —— ある問いは守るが、人が訊くはずの問いは守らないゲート。

1. 全テストが避けていた道

mvm start を引数なしで打つと 20 GiB のディスクができる。 そのディスクは mke2fs が成功を報告した瞬間から壊れていた:

disk: mke2fs ok
EXT4-fs error (device vda): bg 32: bad block bitmap checksum
EXT4-fs error (device vda): ... bg 49 ... bg 64 ... bg 96 ... bg 128 ...
disk: done                      ← 「できた」と言う

次の起動でカーネルは Block bitmap for group 0 not in group (block 4294967295) と言って panic した。この数は 2³² − 1 で、壊れている group —— 32 / 49 / 64 / 96 / 128 —— はちょうど 4 GiB の線より上に住んでいるものだ。

原因は宣言だった。自作言語の int は 64bit だが、C backend が extern に吐く宣言は素の int で、shim 側は long long で定義していた:

extern int hv_guest_to_file(const char*, int, const char*, int);      /* 呼ぶ側が信じているもの */
long long  hv_guest_to_file(const char*, int, const char*, long long); /* 定義しているもの */

両方のファイルが警告なくコンパイルされる。 そして呼ぶ側が、渡す途中で引数を切る。呼び出し箇所には何も見えない。 何かを直す前に測った: 20 GiB のディスクへの 34,341 回の書き込みのうち、 4 GiB を超えたものが 1 つも無い。 最大は 4,294,963,200 —— 2³² からページ 1 つぶん引いた値。 線より上への書き込みは全部、ファイルの先頭に折り返して生きているデータを上書きしていた。

直し方は作法 1 行ぶんだ。オフセットを hex 文字列で渡す —— 同じ関数の隣にいるゲスト物理アドレスが、最初からそうしていたのと同じに。 直した後は 34,397 回のうち 33,144 回が 4 GiB を超え、format は綺麗で、 線より上に書いたデータはマシンの再起動をまたいで残る。

なぜ何も捕まえなかったか。 ゲートは 14 本あった。渡している引数はこうだ:

test/lifecycle.sh  --disk-size 2048
test/scale.sh      --disk-size 4096
test/build.sh      --disk-size 1024 / 2048 / 1024
test/outward.sh    --disk-size 4096
test/vcpus.sh      --disk-size 4096

1 本も省略していない。 全部が既定値を上書きしている。 小さい方が速いという当たり前の理由で、そしてその一貫性こそが穴を隠していた。 一度も通っていなかったのは、人が何も付けずにコマンドを打つ道だけだった。

これは自分のプロジェクトを超えて一般化するので、はっきり書いておきたい —— 既定値が未検査なのは、まさに全テストがそれを上書きしているからだ。 15 本目のゲートは、いま人と同じようにマシンを起動する。 そして切り捨てを元に戻す sed を一緒に持っている。

2. 説明できないので印字しておいた数字

80 並列の docker run で、上がってくるコンテナが 72〜79 個のあいだで揺れた。 クライアントは全部成功を報告する。4 回測って 2 つの仮説を反証したので、 正直だと思えることをした —— 数を印字して、要求はしなかった。

note  72 of 80 came up -- reported, not required

理解していない数に対してこうするのは、擁護できる振る舞いだ。 そして同時に、「既知の未知」が永住権を得る経路でもある。

破ったのは 5 回目の同じ測定ではない。4 回とも 「何個上がったか」=症状を数えていた。 docker CLI とデーモンの間に記録するリレーを挟み、 接続を**「開いた時」にも**記録させた。閉じた時だけではなく。 この 2 つ目が全部で、閉じた時だけ記録する計器は、終わったリクエストを見せて 終わらなかったものを消す —— そして探しているのは後者だ。

1 回、80 クライアント:

POST /containers/create     開 80   閉 80
POST /containers/ID/wait    開 80   閉  0
POST /containers/ID/start   開 32   閉  0

start が 32 本。 80 ではない。 32 はデーモンが持っているバッファスロットの数で、あとは 自分が数ヶ月前にコメントに書いていた設計の細部から follow する —— docker CLI は /wait自分専用の接続で開き、/start を送るのは /wait のヘッダが返ってきてからだ。 つまり 80 本の wait が来て、32 本がスロットを取ってヘッダを返し、 その 32 クライアントが /start を送り —— その start は全部、 待っている /wait が握っているスロットを待つ。 その /wait は、始まれないコンテナが終わるのを待っている。 循環待ちで、しかも輪が同じクライアントの 2 本の接続を通っている。

間欠的なのは競争だからだ。40 クライアントなら、wait が全スロットを埋めきる前に start が滑り込むことが多い。並列数を上げるほど悪くなり、 どの閾値も綺麗に見えなかった理由がこれだ。

直しは 4 行 —— /waitポーリングを始める前にスロットを返す。 その先でバッファを使うことは無かった。結果:

クライアント完了 /wait /start
直す前 0 / 80 開 80・閉 0 開 32・閉 0
直した後 80 / 80 開 80・閉 80 開 80・閉 80

そして探していなかった数字がもう 1 つ出た。15 本のゲート全体が 1291 秒から 561 秒に、scale 単体で 765 秒から 54 秒になった。 ゲートは毎回 12 分をデッドロックの中で座って過ごしていた。 私はそれを「遅いゲート」と呼んでいた。

3. 訊かないまま「意味が成立しない」と書いた能力

元の記事には「やらないこと」という節があり、その最初の項目はこうだ:

外向き NAT —— 変換する先の上流インタフェースが存在しない

この文は NAT については正しく、その後ろにあるものについては間違っている。 覚えている設計から推論していて、ゲストのカーネルに何があるかを一度も訊いていなかった。 訊いたら:

netfilter の芯 あり(組み込み)
ip_tablesnf_nat 無し
/dev/net/tun 無し
読み込み済みモジュール 8 個 —— Image の隣に同梱している全部

だから正直な言い方は「意味が成立しない」ではなく「モジュールが 6 本足りない」だ。 これは値段で、値段は代替と比較できる —— そして「意味が成立しない」は、まさにその比較を 3 セッションぶん妨げていた。

値段が出た途端に安い方が見えた。本当に欲しい能力は任意の外向き TCP で、 SOCKS5 はそれをほぼタダで買える。既に走っている CONNECT プロキシと 同じ 2 本のソケット、同じコピーループで、最初の 1 バイトがどちらのプロトコルかを言うので 1 つのポートで両方答えられる。その 1 バイトを消費せずに覗くのが要点で —— SOCKS5 の挨拶は 3 バイトで改行が無いから、先に行を読むと 10 秒待った末に、 正しく喋ったクライアントに 405 を返すことになる。

$ docker run --rm alpine sh -c 'printf "QUIT\r\n" | curl -sS telnet://smtp.gmail.com:25'
220 smtp.gmail.com ESMTP ...

ネットワークインタフェースを 1 枚も持たないコンテナが、 HTTP を聞いたこともない相手と素の TCP で会話している。

それでも運べないもの —— これが、間違っていた文の置き換えだ —— は、どちらのプロトコルも喋らない相手: ncpingpsql。 これらは経路を欲しがり、経路は例の 6 本を欲しがる。

ゲートはページではなくバイトで訊く。 何でも受け入れるプロキシと、ちゃんと動くプロキシは、 ページを 1 枚取るだけの検査ではどちらも緑になるからだ: CONNECT0x00、実装していないコマンドは 0x07、 存在しない名前は 0x04、そしてプロキシが持っていない認証方式だけを提示した クライアントには、愛想よく「認証不要」ではなく 0xFF を返す。

4. オプションを 1 つ書いたらコマンドが 2 つ消えた

一番小さくて、形としては一番純粋なものだ。

mvm --help はスクリプト先頭のコメントブロックで、こう切り出していた:

usage() { sed -n '3,14p' "$0" | sed 's/^# \{0,1\}//'; }

そのブロックに 1 行足した —— 新しいオプションを説明する行だ。 それが mvm statusmvm doctor を 14 行目の外へ押し出した。 ツールは両方を受け付け続け、言うのをやめた。

どのテストも気づけない、そこが面白いところだ —— 単に未記載なだけのオプションは、既に存在を知っている人には完璧に動く。 どこにも失敗する振る舞いが無い。見つける方法は、 一度も突き合わせたことのない 2 つを突き合わせることだけだ: 引数パーサが受け付けるものと、ヘルプが印字するもの。

だから突き合わせるものを書いた。書いた直後に、未記載のオプションを 4 つ見つけた: --publish--version--kversion--from-dir。 そして最初に書いたとき、私は一段上で同じ種類の間違いをした —— ファイル引数を取るので汎用に見えるのに、書いた相手 1 本でしか動かなかった。 2 本目のツールに当てたら、5 つのオプションを全部正しく記載しているスクリプトに対して 「抽出が壊れている」と報告した。1 人目の利用者では、汎用のふりは見抜けない。

4 つの欠陥、1 つの形:

  • ゲートはあった。そして問題になる入力を上書きしていた
  • 数は、説明できないという理由で要求ではなく報告にされていた
  • 境界は、測られずに推論されていた
  • 一致すべき 2 つの成果物が、一度も突き合わされていなかった

どれも「テストが無かった」ではない。4 つとも、緑のスイートの中にいて、 互いに一致している検査の隣にいた。毎回欠けていたのは問いで、 欠けていた理由は毎回同じだ —— 簡単な方の問いも、同じ緑を出す。

出てきた習慣が 3 つある。どれも安い:

  1. 自分のテストのうち何本が既定値を上書きしているか数える。 全部だったら、その既定値は誰も一度も試していない唯一の入力だ。 grep -c が 1 秒で教えてくれる。
  2. 説明できない数が出たら、その 1 段下を計器にする。 同じ数を 5 回目に測るのではなく。 「何個上がったか」は結果で、「何本の接続が開いて何本が閉じたか」はそれを作っているものだ。 そして両端を記録する —— 完了だけ記録する計器は、見たい失敗をちょうど隠す。
  3. 「不可能」と書く前に、機械に訊く。 足りない部品を名指しし、それぞれに値段をつけ、 そのうえで決める。値段こそが、安い代替を見えるようにする。

元の記事は、この基盤の一番価値ある産物は言語について見つかった欠陥の一覧だ、と言って終わった。 ここの 1 つ目のバグはその一覧に加わる —— コンパイラが 64bit 整数に対して吐く C の宣言は言語の契約の一部で、 私のそれは静かに幅を狭めていた。 だが残りの 3 つは、作ったものではなく、確かめ方の欠陥だった。 そちらの方が遠くまで移植できると思う。 この基盤は私のもので、変わっている。 「面白い入力を避けることで全員が一致してしまったテスト群」は、そうではない。

← Back to Notes