個人開発している Web アプリが、そろそろ Closed Alpha まで来そうだ。
結構うれしい。
今回はかなり本気で、ダークファクトリー的な開発を目指している。
僕が「こんな機能がほしい」と指示する。AI がコードを書く。テストを書く。動かす。問題があれば直す。僕は出来上がったものを確認して、次の指示を出す。
これを繰り返している。
もちろん完全無人というわけではないけれど、少なくとも僕自身がコードを書くことはかなり減った。
そして、マジでアプリケーションが出来上がっていく。
すごい。
前にもダークファクトリーについて書いたけれど、実際に自分でやってみると未来感がすごい。
「これ、ソフトウェア開発のやり方、本当に変わるんじゃないか？」
などと思いながら、僕は出来上がりつつあるアプリケーションを眺めていた。
Closed Alpha も見えてきた。
いいぞ。
ワイもダークファクトリーや！
所で、最近トップページがもっさりしている。
計ってみる。
3000ms オーバー。
……
…………
ウッソだろ！？ まだ、ユーザ数1人だぞ！？
このアプリは Go と Neon DB、それから Go に埋め込んだ HTML で作っている。フロントエンドで巨大な JavaScript を読み込んでいるわけでもない。それなのに、メインページを開くのに3秒以上かかる。
ちなみにローカルで動かすと70msを切る。
何かがおかしい。
まずログを見る。しかしそこには何もない。何もだ。
こういうときは、まずログを見る。
一応、僕もプログラマを20年くらいやっている。3秒という数字だけ眺めながらコードを片っ端から読むようなことはしない。
ログを見て、どこで時間を使っているのか調べる。
ところがどっこい、ログなんてありません。
ぼくはダークファクトリーを目指した。そんな訳て、このアプリは、かなりAIに実装を任せている。
「こんな機能がほしい！」
と指示する。
AIが実装する。テストする。動く。
では次の機能。
そんな感じで、最小限の機能をインクリメンタルに積み上げてきた。
すると、「どんなログをどこに仕込むか」を指示する機会がない。
僕が自分でコードを書いていたら、おそらく違った。
開発中にデバッグしたくなるので、「ここどうなってるんだ？」となって、とりあえずログを出す。別に立派なObservability戦略があるわけではない。自分が困るから入れる。print デバッグはいつの時代もプリミティブかつ有用である。
ところが今回は、その工程そのものをAIに渡している。
機能は増えた。
ログは増えなかった。
仕方がないので、まずリクエストログを整備した。フォーマットを決めて、所要時間、ステータス、リクエストとレスポンスのボディサイズを出す。セッションごとに絞り込んで見られるようにもした。
これでわかったのは、ブラウザとサーバ間のネットワークが遅いわけではないということだった。
サーバ側で3000msかかっている。
目も当てられない。
OpenTelemetryを入れる
次に欲しいのはメトリクスとトレースだ。もちろん指示しない限り、AIは自動的に入れてくれない。
いつも通りのOpenTelemetry を入れることにした。コーディングエージェントは「時期尚早」と言う。いや、いま困ってるんよ。
Prometheus や Zipkin みたいな構成をイメージすればいい。計装は一度入れてしまえば、あとは自動で測ってくれるのがいい。
ただし、個人開発なのでトレースを受け取るためだけの環境を真面目に作りたくはない。金もかかる。
なので、トレースはリクエストログに続けてテキストで出力することにした。
DBライブラリとサーバライブラリは自動計測。ビジネスロジックには必要なところにspanを設定した。
これでようやく、3000msの中身が見える。
1200ms以上かかっているDBクエリが一件。
200msくらいかかっているクエリが数件。
なるほど。
なるほど？
な、なるほどぉ！？
シンガポールは遠い
そもそも1クエリに100ms以上かかるのはおかしい。
ただし、心当たりはある。
Neon DBはシンガポールにある。そしてアプリケーションサーバは関東にある。
遠い。
これについてはいくつか対応方法がある。
接続をプールしてもいい。独立したDBアクセスを並列化してもいい。キャッシュしてもいい。DBそのものを関東へ持ってきてもいい。
逆にアプリケーションをシンガポールへ持っていく手もあるが、これはちょっと躊躇する。DBとの距離は縮まるけれど、今度は日本のブラウザからアプリケーションまでが遠くなる。HTTPリクエスト側を分散させることも考えると、単純にアプリをDBの隣へ持っていけばいいとも限らない。
まあ、この辺はあとでいい。
200msのお前らはあとでまとめて面倒を見る。
1200ms、お前はダメだ。
一体何をしているんだ。
そこで、ようやくクエリを見ることにする。
全件取得ちゃん
なんということでしょう……
唯一のユーザである僕のデータを600レコード全部取得して、それでページングによって10件だけレンダリングする……
豪華な使い方やでほんま……
許されるはずがない。
ローカルのDBには高々100件くらいしかレコードがない。100件なら全部取ってきても問題は顕在化しない。
本番環境には10kレコードオーダーでデータがある想定だ。
許される……はずがない……。
では、なぜこんな実装になったのか。
過去を振り返ってみる。
僕はAIにこう言った。
「こんな機能がほしい！」
以上。
そこに非機能要件なんて入っていない。
データが増えたときにどうするのか。何件までを想定するのか。全件取得を避けるのか。どの程度のレスポンスタイムを許容するのか。
そんなことは指示していない。
AIは要求された機能を実装した。
ローカルでは動いた。テストも通った。
何も間違っていない。
いや、全件取得はやめろよ、とは思うけれど。
3000msから150msへ
全件取得ちゃんを修正した。
すると3000ms以上かかっていたレスポンスは、だいたい150msくらいになった。
めでたい。
そして一匹いたということは、当然ほかにもいる可能性がある。
泣きながらコーディングエージェントに「全件取得が起こり得るパターンをリストアップしてくれ」とお願いして、一つずつ潰した。
簡単なお仕事である。
本番サービスを始める前に見つかって本当によかった。
レスポンスが3秒かかるだけなら、ユーザーが怒る。
全件取得を繰り返して転送量まで増え始めたら、僕が泣く。
下手すると破産する。
「普通こうするよね」はどこに行ったのか
今回の件は、単純に「AIがクソコードを書いた」という話ではない気がしている。
もちろん、10kレコードを毎回全部取ってくるのはやめてほしい。
ただ、人間のプログラマに同じ機能を頼んだとしても、仕様書に「全件取得は禁止です」と書いてあったわけではない。
経験のあるプログラマなら、たぶん避ける。
なんとなく嫌だからだ。
データが今後増えそうだとか、この処理は何度も呼ばれそうだとか、あとで絶対面倒になるとか。
20年くらいプログラムを書いていると、そういう「嫌な予感」が大量に蓄積される。
ログもそうだった。
僕が自分で実装していたら、「ログを実装する」というタスクを切らなくても、デバッグ中に困って勝手にログを仕込んでいたと思う。
つまり、人間がコードを書くという工程には、仕様には書かれていない非機能要件が大量に混ざっていたらしい。
ダークファクトリー的に人間を実装工程から外すと、それも一緒に消える。
では、最初から全部AIに指示すればいい。
性能要件を書こう。
ログ要件を書こう。
監視要件を書こう。
全件取得は禁止しよう。
N+1も禁止しよう。
……それで全部だろうか。
僕には、そうは思えない。
経験のあるプログラマが無意識に避けているものを、あらかじめ全部列挙できるだろうか。
少なくとも僕にはできない。
今回の3000msは150msになった。
まだ並列化もしていないし、コネクションプールもキャッシュも入れていない。Closed Alphaの結果が良ければ、NeonからFly.ioのManaged Postgresへ移すことも考えている。
本質的には、アプリケーションとDBが同じネットワークにいないことが問題だからだ。
ただ、それには金がかかる。
150msなら、とりあえず今はこれでいい。
今回の全件取得ちゃんは見つけた。
では、まだ僕が言語化していない「普通こうするよね」は、あといくつあるんだろう。
よくわからない。
ダークファクトリー、なかなか興味深い。