Chillarin Trading Lab · トラブル記録

再起動したら資産が2倍に増えてた — システムのよくある罠にハマった話

再起動で静かに壊れた金融 bot を、DB とログと口座照会の三点突き合わせで直すまで

trading 2026-06-04 61 min read by chillarin
cover · 1024×1024

はじめに

2026 年 6 月 3 日、サーバーを再起動した後、米国株自動売買のダッシュボードが妙な数字を出していました。元手 $1,500 の Fund A(AI が中長期で保有を判断する戦略)が、資産 $2,906。プラス 93.8%、ほぼ倍です。

最初に書いておきます。これは成績ではありません。表示のバグです。 Fund A は本来この時点でマイナス成績のはずで、一晩で倍になる理屈はどこにもありません。にもかかわらずダッシュボードは堂々と「+93.8%」と表示していました。

原因は設定ミスではありませんでした。再起動のときだけ静かに壊れるバグです。DB がまだ起動しきっていないのに売買プロセスが先に立ち上がり、状態の復元に失敗したのにエラーを握りつぶして、そのまま走り出していました。

そもそも CTL で本物のお金を動かし始めたのは、つい先日、6 月 1 日のことです。そのわずか中 2 日で、いきなりこのトラブルに出くわしました。ペーパートレード(仮想の売買)では一度も顔を出さなかった種類の問題で、実際にお金を動かし始めると、想定していなかったことが次々に起きます。動かしてみて初めて分かることがある。だからこそ記録しておく価値がある、と思って書いています。 ※今後も様々なトラブルが出てくると思いますが、都度投稿していきますので、ドタバタ劇場をお楽しみください。

この記事は、その異変に気づいてから、DB とログと口座照会を端から突き合わせて真因にたどり着き、fail-fast に作り直すまでの一次記録です。煽るような話ではありません。金融を扱う bot が「静かに壊れる」とどうなるか、という淡々としたインシデント報告として読んでください。


異変 — ダッシュボードが「資産ほぼ2倍」

Chillarin Trading Lab(以下 CTL)では、性格の異なる 2 つの戦略を少額の実際の資金で並走させています。今回トラブルを起こしたのは Fund A です。AI が値動きの勢い(モメンタム)が上位の銘柄に集中して投資し、長めの移動平均線がデッドクロスしたときにだけ売る、中長期保有型の戦略です。元手は実際の資金 $1,500。

6 月 3 日にサーバーのメンテナンスで再起動をかけました。その後、ダッシュボードを開くと Fund A の資産がこうなっていました。

項目表示値
元手(初期資金)$1,500.00
現在の資産$2,906.97
損益+$1,406.97(+93.8%)

一晩で倍。普通なら喜ぶところですが、これは喜べる数字ではありません。Fund A は前日まで小さくマイナスで推移していて、6 月 3 日に大きな相場の動きがあったわけでもない。何より、保有していた銘柄の値動きだけでこの増え方を説明することは不可能でした。

数字が良すぎるときは、たいてい良いことが起きているのではなく、計測のどこかが壊れています。この「資産2倍」は成績の話ではなく、ダッシュボードの土台にあるデータが壊れているサインだ。そう見当をつけて、原因の切り分けを始めました。


設定ミスを疑った。でも違った

最初に疑ったのは、ありがちな設定ミスです。元手の金額をどこかで二重に入れてしまったとか、別の戦略の数字が混ざったとか、その類いです。

しかし設定を確認しても、おかしなところはありませんでした。初期資金は $1,500 で正しく、別の戦略の値が紛れ込んだ形跡もない。設定ファイルは前日から一文字も変わっていませんでした。

ここで一つ、調査の過程で見えた CTL の内部構造に触れておきます。CTL の物理的な証券口座は実は 1 つで、現金プールを共有しています。その 1 つの口座を、DB 上の状態テーブル(戦略ごとに 1 行)で「Fund A の枠 $1,500」「Fund B の枠 $1,500」という具合に論理的に分割して管理する設計です。「それぞれ $1,500 のつもり」が、実体としては「1 つの物理口座を論理枠で切り分けている」。今回の調査の入口で、この二重構造を改めて意識することになりました。

そして設定が正しいとなると、疑いは「動いている最中に状態が壊れた」方向に向きます。設定は静的なファイルなので、再起動で勝手に書き換わったりはしません。壊れるとしたら、プロセスが起動するときにメモリ上へ状態を組み立てる過程です。当たりをつける先が、設定から実行時の挙動へ移りました。


DB・ログ・口座を突き合わせる

ここからが本題です。表示が信じられない以上、表示の元になっているデータを一次情報まで遡って、複数の経路で突き合わせるしかありません。CTL には幸い、観察できる経路が複数ありました。

  • DB(TimescaleDB)の状態テーブル — 現金・保有銘柄・実現損益が記録されている
  • DB の equity_history テーブル — 日々の資産額のスナップショットが残っている
  • プロセスの起動ログ — 起動時に何をしたかが時系列で残る
  • 証券会社の口座照会 — 実際に約定した注文と現在の保有

この 4 つを並べた瞬間に、矛盾の構造が見えてきました。

equity_history が「あるべき姿」を覚えていた

決め手になったのは equity_history テーブルでした。ここには日次の資産額が淡々と記録されていて、再起動前までの値はこうなっていました。

日付Fund A の資産額
6/1$1,500.00
6/2$1,493.93

6 月 2 日時点で $1,493.93。元手 $1,500 に対してわずかにマイナス。これが「あるべき姿」です。一晩で $2,906 になる連続性はどこにもありません。過去の自分が残した記録が、現在の表示が嘘であることを証明してくれたわけです。

起動ログにレースの痕跡があった

次に起動ログを見ると、再起動直後の時系列にはっきりした痕跡が残っていました。売買プロセス(real-trader)が立ち上がった時刻と、DB コンテナが応答を返せるようになった時刻を並べると、プロセスのほうが先に起動していたのです。

そしてプロセスが起動直後に状態を復元しようとした行に、こんなログが残っていました。

snippet
[ERROR] _restore_state failed: the database system is starting up

the database system is starting up は、PostgreSQL(TimescaleDB はその拡張です)がリカバリ中でまだ接続要求に応えられないときに返すメッセージです。つまり、

  1. サーバー再起動で全部が一斉に立ち上がろうとした
  2. real-trader プロセスが、DB コンテナがリカバリを終える前に起動してしまった
  3. 状態を DB から復元しようとしたが、DB は「まだ起動中だ」と突き返した

ここまでは「タイミングが悪かった」だけの話です。問題はこの次に何が起きたかでした。

例外を握りつぶして、そのまま走り出していた

当時の状態復元処理 _restore_state は、こういう構造になっていました。

python
try:
    # DB から現金・保有・実現損益を読み戻す
    ...
except Exception:
    log.error(...)   # ログを吐くだけ
    # ← そのまま処理を続行してしまう

DB から状態を読めなかったのに、例外をログに書くだけで握りつぶし、何事もなかったかのように起動を続けていたのです。

復元に失敗したので、メモリ上の現金は復元されず、初期値の $1,500 のままで走り出しました。一方、保有銘柄のほうは別の経路で生きていて、再起動の少しあと、DB がリカバリを終えてから読み込まれた GOOGL と WMT が復活しました。

ここで二重計上が成立します。

  • 現金: 復元に失敗して初期値 $1,500 に戻ったまま
  • 保有銘柄: あとから復活した GOOGL / WMT の評価額

本来、保有銘柄を買った分だけ現金は減っているはずです。ところが現金は「買う前」の $1,500 に戻り、保有銘柄は「買ったあと」の状態で復活した。現金と保有を、時間軸の違う 2 つの瞬間から拾ってしまった結果、資産が水増しされました。

さらに悪いことに、起動後の通常サイクルで、この bot は偽の現金 $1,500 を見て「まだ買う余力がある」と判断し、GOOG を追加で買い付けました。本来の枠を超えた買い付けです。これで現金と保有がさらにふくらみ、最終的にダッシュボードは $2,906 を表示するに至りました。

真因は、DB とログと口座照会の三点が一致したことで確定しました。設定ミスではなく、再起動時のプロセス起動順のレースと、その失敗を握りつぶす例外処理。これが嘘の表示を生んだと判明しました。


二重計上の検算

真因が分かったら、表示された数字が「偽の現金+復活した保有」できれいに再現できるかを検算しました。ここが合えば、推定が事実に変わります。

まず、bot が偽の現金 $1,500 を元手だと勘違いして買い付けた GOOG の分。

snippet
現金 $771.61 = $1,500.00 − GOOG $726.28 − 手数料 $2.11

次に、ダッシュボードが表示していた資産額。

snippet
表示資産 $2,906.97 = 現金 $771.61 + 保有評価 $2,135.36

偽の現金 $1,500 を起点に GOOG を買った残りの現金 $771.61 と、復活した保有銘柄+追加で買った GOOG の評価額 $2,135.36 を足すと、ダッシュボードの表示値 $2,906.97 にぴったり一致しました。

一方、equity_history が覚えていた正しい値は 6/2 時点で $1,493.93。正しい姿は約 $1,494、壊れた表示は約 $2,907。差のほぼ全額が、二重計上と枠超過の買い付けによって生まれた幻の資産でした。検算が合ったことで、真因の説明が数字の上でも閉じました。


fail-fast への作り直しと「論理枠の保存則」

原因が分かったので、同じことが二度と起きないように直しました。考え方はひとつです。状態を正しく復元できないなら、間違った状態で走り出すより、起動を止めて気づかせるほうがましだ。「静かに壊れて走り続ける」のが今回いちばんの問題だったので、その逆、つまりfail-fast(早く・はっきり失敗する)に倒しました。対策は 4 つです。

1. DB 接続にバックオフ付きリトライを入れる

そもそも「DB がまだ起動していないのに接続を試みて一発で諦める」のが発端でした。DB 接続を取る処理に、待ち時間を少しずつ延ばしながら接続を試す指数バックオフのリトライを入れました。総待ち時間は systemd の起動タイムアウト(60 秒)を超えないように収めてあります。これで、DB が数秒遅れて立ち上がる程度のレースは吸収できます。

2. 状態復元を fail-fast 化する

今回の元凶だった例外の握りつぶしを撤去しました。_restore_state を囲っていた外側の try/except を取り払い、復元に失敗したら例外をそのまま上に伝えてプロセスの起動を中止させます。中途半端な状態で走り出すくらいなら、起動を止めて通知を飛ばすほうが安全です。

3. 起動時に「論理枠の保存則」を検証する

これが今回いちばん効く対策です。状態の復元処理が終わった直後、まだ通常の売買サイクルに入る前のタイミングで、メモリ上の状態が辻褄の合った状態かを必ず検証する _assert_state_consistent() を新設しました。復元(対策 2)に成功しても、その中身が壊れていないかをもう一段確かめる、という位置づけです。

考え方は単純です。論理枠の中では「現金+保有銘柄の簿価」が、おおむね初期資金に等しくなるはずです(実現損益のぶんだけずれる)。今回の壊れ方は、まさにこの保存則が破れていた状態でした。

python
# 時価 (market_value) でなく簿価 (cost_basis = avg_price×qty) で評価する
# ことで、値動きによる誤検知を避ける。
invested = sum(p.cost_basis for p in self.positions.values())
logical = self.cash + invested
drift = abs(logical - self.initial_cash)
# realized_pnl が cash に乗るぶんと、運用上の許容ゆらぎ (枠の5% or $50) を許容。
tol = abs(self.realized_pnl) + max(0.05 * self.initial_cash, 50.0)
if drift > tol:
    raise RuntimeError(...)  # 起動中止 (fail-fast)

一点、設計上こだわったところがあります。保有銘柄の評価に時価ではなく簿価(取得単価 × 株数)を使うことです。時価で評価すると、株価が動いただけで「現金+保有」が初期資金からずれてしまい、健全な値動きを不整合と誤検知してしまいます。簿価で見れば、値動きそのものはノイズにならず、「買った分だけ現金が減っているか」という保存則だけを純粋に検証できます。

判定は、保有銘柄の有無と状態テーブルの行の有無で 2×2 に整理しました。

状態行保有銘柄判定
なしなし新規ローンチ。初期資金で続行(正常)
なしあり不整合(保有があるのに状態行が消えた)→ 起動中止
あり論理枠の保存則をチェック。逸脱なら起動中止

今回のバグは「状態行はあるが、現金と保有の辻褄が合っていない」ケースで、この保存則チェックに引っかかって起動が止まります。

4. systemd で二段の防御を張る

最後に、アプリの外側、systemd のユニット定義でも守りを固めました。DB が応答できるようになるまで起動を待たせ、それでも起動に失敗したら通知を飛ばす構成です。

ini
After=network.target opend.service docker.service
OnFailure=notify-failure@%n.service
# DB が接続可能 (pg_isready=accepting) になるまで最大 60s 待つ。
# pg_isready はリカバリ中 (starting up) は終了コード 1 を返すので、success まで待てる
ExecStartPre=/bin/bash -c 'for i in $(seq 1 30); do docker exec trading-timescaledb-1 pg_isready -U trading -q && exit 0; sleep 2; done; ...'

ポイントは ExecStartPrepg_isready を成功するまでループ待ちさせるところです。pg_isready は DB がリカバリ中(starting up)のあいだは終了コード 1 を返すので、「接続を受け付ける」状態になるまできちんと待てます。After=docker.service で起動順も整え、OnFailure で起動に失敗したら LINE に通知が飛ぶようにしました。アプリ内のリトライ(対策 1)と、その外側の起動順制御(対策 4)で、レースを二段で潰す形です。


壊れたデータをどう直したか

コードを直しても、すでに DB に書き込まれてしまった「幻の保有銘柄」は残ったままです。これも片付ける必要がありました。

問題は、bot が偽の現金で誤って買い付けた GOOG 2 株です。ここで一つ判断したのは、この 2 株を実際に売却して処理しないことでした。誤発注とはいえ実際に市場で売れば、無駄な手数料が発生し、売買履歴にも不要な記録が残ります。そうではなく、DB 上で GOOG 2 株を別枠(buffer)に移管する形で帳尻を合わせました。positions(保有)と orders(注文履歴)の両方を移し替え、Fund A の状態を、バグが起きる前の正常な姿に戻しました。実際の取引はゼロです。

この補正で一点だけ順序が重要でした。DB を直接書き換える作業は、real-trader を停止した状態で行うことです。プロセスが動いたままだと、次の保存処理でメモリ上の(壊れた)状態が DB に上書きされてしまい、せっかくの補正が消えます。プロセスを止めてから DB を UPDATE し、正しい状態にしてから起動し直す。この順番を守って、Fund A は現金 $53.28 という、バグが起きる前の正常な状態に戻りました。


これからの改善

ここまでに挙げた 4 つの対策(接続リトライ・fail-fast 化・論理枠の検算・systemd の二段防御)は、6 月 4 日時点で実装して稼働させています。これらはいずれも「起動のときに辻褄を確かめ、合わなければ走り出さない」という、起動時の防御です。一方で、起動を無事に通り抜けたあと、通常の売買サイクルに入ってからの守りはまだ手薄なままです。関連して詰めておきたい点が 3 つ残っているので、次にこの順で手を入れる予定です。

ひとつめは、論理枠のハードキャップです。発注の手前で「いま保有している銘柄の簿価合計 + これから出す注文の金額」が初期資金(定数)を超えないかを検査して、超えるなら注文そのものを弾きます。今回の止血が「壊れた現金では起動しない」だったのに対し、これは壊れた現金を信じてしまっても、発注の段で必ず止まるようにする、もう一枚の防壁です。起動時のチェックをすり抜けて誤った現金を抱えたまま走り出してしまっても、実際にお金を動かす最後の一歩でブレーキがかかる。起動と発注の二段で守る形にしたいと考えています。

ふたつめは、証券口座の実際の買付余力のチェックです。論理枠のハードキャップは、あくまで DB 上の論理的な枠を超えていないかを見るものです。それとは別に、物理的な口座の現金が本当に尽きていないかを確かめ、足りなければ発注を止める最後の砦も足したいと考えています。理由は単純で、CTL の物理口座は戦略間で 1 つを共有しているため、Fund A の論理枠だけを見ていても、口座全体の現金が他方で使われていれば守りきれないからです。論理の枠と物理の残高、両方を見て初めて発注の安全を担保できます。

みっつめは、再起動時の状態復元の取りこぼしへの対応です。今回の調査の過程で、保有している銘柄が再起動後に価格の購読リストから漏れ、現在値が更新されないままになることがあると分かりました。そこで、起動時に保有銘柄を必ず価格の購読リストへ戻す処理も入れる予定です。これで、再起動後に「保有はあるのに値が動かない」という取りこぼしを防ぎます。

いずれもこのあと手を入れ、実際に稼働させたうえで、どこまで効いたかを続編にまとめました(資産2倍バグのその後 — 再起動が暴いた5つの不具合を直す)。実際に直してみると、1 回の再起動が炙り出した弱点はここで挙げた 3 つにとどまらず、発注ガードを足す場所の間違いやタイムゾーン基準の食い違いまで連鎖していました。


教訓 — 金融 bot の「静かに壊れる」は金額の桁を変える

今回いちばん怖いと感じたのは、バグそのものよりも壊れ方が静かだったことです。

プロセスは正常に起動したように見え、ダッシュボードは堂々と数字を表示し、エラー画面もアラートも出ませんでした。出ていたのは、ログの奥に埋もれた _restore_state failed の 1 行だけ。握りつぶされた例外は、誰にも気づかれないまま「+93.8%」という嘘の成績に化けていました。しかも厄介なことに、起動後の bot は偽の現金を本物だと信じて、枠を超えた買い付けまで重ねていました。表示が狂っただけでなく、実際に動かす金額のほうも狂い始めていた。気づくのが遅れていたら、と思うと今でも少しひやりとします。

真因にたどり着けたのは、観察できる経路が複数あったからにほかなりません。今回それぞれが果たした役割は、こうでした。

  • ダッシュボードの数字(壊れていたが、異変に気づく入口になった)
  • equity_history テーブル(過去の正しい値が「あるべき姿」を証明した)
  • 証券会社の口座照会(実際の約定という一次情報で裏を取れた)

この三点を突き合わせられなかったら、真因は掴めなかったと思います。ダッシュボードの数字だけ見ていたら「やけに増えたな」で終わっていたかもしれないし、ログだけ追っていても、それが実際の口座とどうずれているのかは確かめられませんでした。表示が壊れても別の経路に正しい記録が残っていて、そこから正解を逆算できた。「静かに壊れる前提で観察を仕組んでおく」という普段の心がけが、金融という条件の上で効いてくれた瞬間でした。

そしてコード修正の本丸が、派手な機能追加ではなく「復元できないなら起動を止める」「起動時に辻褄を検算する」という地味な fail-fast だった、というのが今回いちばん腑に落ちたところです。便利に走り続けることより、間違ったときに止まれること。お金が絡む実験だと、そのありがたみが実感として分かりました。


関連記事

CTL のほかの記事への入口を置いておきます。


注記

  • この記事は投資助言ではありません。個人が自分の少額資金で行っている実験の、トラブル対応の記録です。
  • 記事内の $ 値は、論理枠(戦略ごとに割り当てた $1,500)の上での金額です。物理的な証券口座の残高そのものではありません。
  • 元手は Fund A・Fund B あわせて $3,000($1,500 × 2)。失っても生活に影響しない範囲に意図的に抑えています。
  • 誤発注した GOOG 2 株は実際には売却せず、DB 上で別枠に移管して補正しました。実際の取引は発生していません。
  • 売買とシステム運用の最終的な判断と結果の責任は、すべて運用している私自身(ちらりんの飼い主)にあります。読まれる方ご自身の投資判断は、ご自身の責任で行ってください。
· · ·

コメント