🛠️開発記録#247(2025/6/8)ログ＆DB 出力を賢く振り分ける設計 ― MMBot 運用で学んだ鉄則

1. はじめに ─ なぜ “ログと DB の分離” がボット運用の死活を分けるのか

結論：
テキストログ と 構造化データ（DB） を “同じ場所／同じ設計思想” で扱うと、
いつか必ず ボットが止まるか、データが飛ぶか、どちらかが起こる。

取引ボット――とくに FR (Funding Rate) × Market Making のように
保有時間が数秒〜数時間 と振れ幅の大きい戦略では、
「1 秒毎に大量に吐き出されるイベントログ」 と
「1 取引で 1 行残る実績レコード」 が同居します。

経験則：
実戦デプロイ後に一番多い障害は “取引バグ” ではなく

「ログ肥大 ⇒ コンテナ停止 ⇒ PanicExit が走らずポジション残る」。
（Mounts denied や No space left on device のクラッシュログを見たことがある人は多いはず）

1.1 失敗談に学ぶ “混在保存” の落とし穴

1. Docker Volume を /app/data 1 つだけにした
   • → 半年で 10 GB 超。CI のキャッシュとぶつかりビルド失敗
2. JSON Lines を SQLite にそのまま INSERT
   • → WAL が 2 GB を超え、再起動時に “database is locked” で立ち上がらず
3. ログローテ設定を忘れてクラッシュ
   • → watchdog も同じ Volume に吐いていて、一緒に巻き込まれ沈黙

1.2 分離設計が生む 3 つのメリット

1.3 本シリーズで扱う “分離” のスコープ

1. ディレクトリレイアウト
   • runtime/<env>/logs/** と runtime/<env>/db/*.db を物理的に分ける
2. コンテナ内パス ＆ マウント
   • Compose で ../runtime/${ENV} を1か所で解決
   • ログは Loguru ローテ、DB は SQLite WAL＋trim_db.sh
3. バックアップ & クリーンアップ
   • cron / GitHub Actions で 30 日 ZIP / DB VACUUM を自動化
4. メトリクス & レポート
   • ログ → Loki / Promtail
   • DB → InfluxDB or Prometheus Exporter

この導入が腑に落ちれば、以降のセクション
「ディレクトリ設計」「ログローテ実装」「DB バックアップ」「失敗パターン」
が “なぜ必要か” を迷わず追えるはずです。

2. ディレクトリ設計の基本原則 ─ runtime/<env>/{logs, db} に集約する理由

MMBot/
├── compose/                  # Docker / CI だけが触る領域
├── runtime/
│   ├── production/
│   │   ├── logs/             # Loguru が 30 d ローテで直書き
│   │   └── db/               # pnl.db, trade.db, etc.
│   └── testnet/
│       ├── logs/
│       └── db/
└── src/                      # アプリ本体

2-1. “runtime” 直下に固定する 3 つの効用

Tips: NVMe, tmpfs, S3 マウント など、
/runtime 配下をストレージ層で切替えるだけでパフォチューンも可能。

2-2. Compose 一発解決の書き方

# compose/compose.yml
services:
  mmbot:
    volumes:
      - ../runtime/${ENV}:/app/data   # logs と db を一括マウント
    environment:
      DATA_DIR: /app/data             # コード側は固定パスで参照

• ENV=production or testnet は compose/.env で切替。
• テストネットを複数走らせたい場合は ENV=tn2 のように拡張してもパス衝突なし。

2-3. .gitignore ワンライナーで事故防止

/runtime/

• 誤って巨大ログを push → リポジトリ爆肥大
• pnl.db に API キーが残る → 意図せず公開
• どちらも 1 行 で完全ブロックできる。

2-4. ディスク容量アラートの閾値

# rules/prometheus.yml
- alert: DiskRuntimeHigh
  expr: node_filesystem_size_bytes{mountpoint="/runtime"} -
        node_filesystem_avail_bytes{mountpoint="/runtime"} > 1.2e9
  for: 5m
  labels:
    severity: warning
  annotations:
    description: "runtime partition >1.2 GB"

3. ログ（テキスト） vs DB（構造データ）──役割の根本的ちがい

鉄則：

• 「必要になったら grep」 → ログ
• 「秒単位で QPS 叩く」 → DB

3-1. “ログを DB に突っ込まない” 原因トップ 3

3-2. ログ→メトリクスの黄金パス

1. Loguru で json=True 出力
2. Promtail (Loki) が level="INFO" event="pnl" を抽出
3. Grafana Loki → sum(pnl) でレポート
4. 長期保存したい行だけ nightly cron で SQLite へ ETL

これで「DEBUG 行は 7 日後に自動破棄・重要指標は SQL で永続化」の両立。

次セクションでは 実装パターン①：Loguru + RotatingFileHandler に踏み込み、
“30 d ログを勝手に回すスクリプト” と ドロップイン設定例 を示します。

4. 実装パターン① — Loguru × RotatingFileHandler で “放置できるログ” を作る

目的はただひとつ。「ログのことは忘れて開発に集中する」
Loguru は 4 行 の設定で

1. ファイル分割（サイズ・日数）
2. gzip 圧縮
3. 自動削除
   をすべて面倒みてくれます。

4-1. 10 MB／30 d ローテ設定 ― src/mmbot/logging_setup.py

from loguru import logger
from pathlib import Path
import os

DATA_DIR = Path("/app/data")         # ← コンテナ内は固定
LOG_DIR  = DATA_DIR / "logs"
LOG_DIR.mkdir(exist_ok=True, parents=True)

logger.remove()  # 既定の stderr をオフ
logger.add(
    LOG_DIR / "MMBot.log",
    rotation="10 MB",               # サイズで分割
    retention="30 days",            # 30 日で自動削除
    compression="gz",               # 古いファイルを gzip
    enqueue=True,                   # マルチスレッド安全
    format=(
        "{time:YYYY-MM-DD HH:mm:ss.SSS} | "
        "{level: <8} | "
        "{extra[session]} | "       # 任意の拡張フィールド
        "{message}"
    ),
)
logger = logger.bind(session=os.getenv("ENV", "dev"))

ここがポイント

4-2. ログ出力サンプル

2025-06-07 12:00:01.234 | INFO     | production | filled BUY 0.02 BTC @ 68,432.5
2025-06-07 12:00:02.002 | WARNING  | production | depth mismatch: bid<ask
2025-06-07 12:00:05.987 | INFO     | production | exit panic -0.62%

• 1 日が終わると：

runtime/production/logs/
  ├── MMBot.log               (今日進行中)
  ├── MMBot.log.2025-06-06_09-12-33_001.gz
  ├── MMBot.log.2025-06-06_14-37-58_002.gz
  └── ...

30 d 後、最古の .gz は自動削除 → ディスクは常に一定容量に抑えられる。

4-3. 開発機で即試すワンライナー

docker compose run --rm mmbot python - <<'PY'
from mmbot import logging_setup
from loguru import logger, _logger
for i in range(200_000):
    logger.info("stress test log line {}", i)
PY

du -sh runtime/testnet/logs
# → 10M    logs   （旧ファイルは即 .gz ＆ 古いものから削除）

4-4. “落としても拾える” Loki 連携 (追加でやっておくと便利)

# promtail-config.yml
server:
  http_listen_port: 9080

clients:
  - url: http://loki:3100/loki/api/v1/push

scrape_configs:
  - job_name: mmbot-logs
    static_configs:
      - targets:
          - localhost
        labels:
          job: mmbot
          __path__: /app/data/logs/*.log*

• .gz も取り込めるので リアルタイム＋過去 30 d が Loki に蓄積。
• Grafana で level="WARNING" をクエリ → 異常パターンだけ可視化。

4-5. よくあるミスとガード

4-6. “30 d ログ” に何を残し、何を切るか

• TRACE／大量 DEBUG は7日で圧縮→削除 の 2 層ローテを推奨
• メトリクス系ログは Prometheus に変換しておくとファイル自体不要

4-7. コード 50 行で “ログ地獄” を回避できた実例

次のセクションでは SQLite WAL + 自動バックアップ に切り替えて、
“構造化データ の肥大化と破損をどう防ぐか” を実装していきます。

5. 実装パターン② — SQLite × WAL モードで “壊れない DB” を作る

ログはローテで解決しました。
次は 構造化データ（trade_log, pnl, depth_snap など）の扱いです。
SQLite + WAL（Write-Ahead Logging） を正しく設定し、
肥大化・ロック・破損 という３大あるあるを潰します。

5-1. なぜ SQLite？ Postgres じゃダメなの？

相性：FRMMbot の “軽量 × 夜間バッチ分析” には SQLite が最短コスト
（チーム開発で複数言語 / 外部 BI が絡むなら Postgres が快適）

5-2. アプリ側の接続設定（db_access.py）

import sqlite3
from pathlib import Path

DB_PATH = Path("/app/data/db/pnl.db")
DB_PATH.parent.mkdir(exist_ok=True, parents=True)

conn = sqlite3.connect(
    DB_PATH, 
    detect_types=sqlite3.PARSE_DECLTYPES,
    timeout=5,            # 秒。WAL なら3〜5で十分
    isolation_level=None  # ← 手動で BEGIN; COMMIT
)
conn.execute("PRAGMA journal_mode=WAL;")
conn.execute("PRAGMA synchronous=NORMAL;")   # WAL＋SSDならOK
conn.execute("PRAGMA foreign_keys=ON;")

5-3. 肥大化を防ぐ trim_db.sh

infra/cron/trim_db.sh（Docker コンテナ用）

#!/usr/bin/env bash
set -e
DB_DIR=/app/data/db
BACKUP_DIR=/app/data/db_backup

# 1) 垢抜けない WAL をチェックポイント
sqlite3 $DB_DIR/pnl.db "PRAGMA wal_checkpoint(TRUNCATE);"

# 2) VACUUM into で一発スリム化
DATE=$(date +%F_%H%M)
sqlite3 $DB_DIR/pnl.db  "VACUUM INTO '$BACKUP_DIR/pnl_${DATE}.zip';"

# 3) 30 日超えバックアップ削除
find $BACKUP_DIR -name 'pnl_*.zip' -mtime +30 -delete

• 所要時間：20 万行 DB で 2〜3 秒
• サイズ削減例：85 MB → 7 MB
• .zip にしたまま S3 へ aws s3 sync すれば長期保管も低コスト

cron 登録（compose/compose.yml 内 watchdog に追加）

watchdog:
  ...
  environment:
    WATCHDOG_CRON: "1"
  volumes:
    - ../infra/cron/trim_db.sh:/etc/periodic/daily/trim_db

Alpine の crond が 03:00 に自動実行。

5-4. “database is locked” を根絶する３チェック

対処 QuickList

• busy>0 → synchronous を NORMAL→FULL へ
• journal_mode=delete → アプリ再起動しながら WAL 再指定
• lsof 複数 → デバッグ用 sqlite3 が握ったまま。プロセス kill

5-5. DB メタメトリクスを Prometheus で監視

# exporter/sqlite_exporter.ini
[databases.pnldb]
dsn="file:/app/data/db/pnl.db?mode=ro"

[[databases.pnldb.metrics]]
name = "sqlite_wal_size_bytes"
help = "WAL file size"
type = "gauge"
value = "SELECT page_count * page_size - (file_size - wal_size) FROM pragma_wal_checkpoint_info;"

5-6. クラッシュしても 60 秒で復旧する手順

• Bot 停止 docker compose stop mmbot

cp db_backup/pnl_2025-06-07_0300.zip db/pnl.db
sqlite3 db/pnl.db "PRAGMA wal_checkpoint(RESTART);"

• 最新バックアップを戻す bashコピーする編集するcp db_backup/pnl_2025-06-07_0300.zip db/pnl.db sqlite3 db/pnl.db "PRAGMA wal_checkpoint(RESTART);"

cp db_backup/pnl_2025-06-07_0300.zip db/pnl.db
sqlite3 db/pnl.db "PRAGMA wal_checkpoint(RESTART);"

• 再起動 docker compose start mmbot
• Verify sqlite3 ... "SELECT COUNT(*) FROM trade_log;"

ポイント：WAL が破損しても VACUUM INTO で作った ZIP は “本体統合済み” なので WAL ファイル不要で即再接続。

5-7. DB レイヤのアンチパターン

5-8. 運用 30 日回して分かった効果

次章では ログと DB を Grafana／Prometheus に統合し、
「どの勝ち筋・負け筋がどの時刻に出たか」を
1 クリックで可視化するダッシュボード構築を示します。

6. ログ＆DB をダッシュボードに昇華する ― Prometheus / Grafana 統合レシピ

「何が・いつ・どこで」 を 3 秒で把握 できれば、
デバッグも改善サイクルも桁違いに速くなる。
ここでは Loguru→Loki と SQLite→Prometheus を組み合わせ、
“収益・リスク・死活” を 1 画面に可視化する 手順を示します。

6-1. 全体スタック図

flowchart LR
    %% ───── 1. ログ → Promtail ─────
    MMBot[MMBot] -- "logs (json)" --> Promtail[Promtail]

    %% ───── 2. DB → sqlite_exporter ─────
    MMBot -- "SQL pull" --> SQLite[(SQLite)]
    SQLite --> Exporter[sqlite_exporter]

    %% ───── 3. メトリクス集約 ─────
    Promtail -- logs --> Prometheus[Prometheus]
    Exporter -- "metrics (PnL, WAL, ...)" --> Prometheus

    %% ───── 4. ダッシュボード表示 ─────
    Prometheus -- dashboards --> Grafana[Grafana]

6-2. Log → Loki：Promtail 設定

promtail-config.yml

server:
  http_listen_port: 9080

clients:
  - url: http://loki:3100/loki/api/v1/push

scrape_configs:
  - job_name: mmbot_logs
    static_configs:
      - targets: [localhost]
        labels:
          job: mmbot
          env: ${ENV}              # production / testnet
          __path__: /app/data/logs/MMBot.log*

ポイント

• Loguru を json=True にしておけば、Grafana で level, exit_reason をフィルタ可。
• 圧縮済み .gz も自動取り込み → 30 d 分さかのぼって検索。

6-3. SQLite → Prometheus：Exporter 2 枚

(a) PnL / 勝敗タグ

exporter/sqlite_pnl.py

from prometheus_client import Gauge, start_http_server
import sqlite3, time

g_ev = Gauge("mmbot_ev_usd", "Expected value (mean PnL)", ['env'])
g_sharpe = Gauge("mmbot_sharpe", "Sharpe ratio 8h", ['env'])

def loop():
    conn = sqlite3.connect("/app/data/db/pnl.db")
    while True:
        rows = conn.execute("""
          SELECT avg(pnl_total_usd), 
                 avg(pnl_total_usd)/stdev(pnl_total_usd)
          FROM trade_log
          WHERE ts_exit_ms > strftime('%s','now','-8 hours')*1000
        """).fetchone()
        g_ev.labels(env=os.getenv("ENV")).set(rows[0] or 0)
        g_sharpe.labels(env=os.getenv("ENV")).set(rows[1] or 0)
        time.sleep(30)

(b) DB サイズ／WAL

sqlite_exporter.ini

[databases.pnldb]
dsn="file:/app/data/db/pnl.db?mode=ro"

[[databases.pnldb.metrics]]
name = "sqlite_wal_bytes"
help = "WAL file size"
type = "gauge"
value = "SELECT wal_bytes FROM pragma_wal_checkpoint_info;"

Dockerfile に組み込み、9109/metrics で公開。

6-4. Prometheus scrape 例

scrape_configs:
  - job_name: 'mmbot_sqlite'
    static_configs:
      - targets: ['mmbot:9109']
  - job_name: 'promtail'
    static_configs:
      - targets: ['promtail:9080']

6-5. Grafana ダッシュボード構成（4 パネルで足りる）

• 総 PnL (USD) 時系列

sum_over_time(mmbot_ev_usd[1h])

• Sharpe Ratio 8 h
  → 赤帯: < 0.5 警告
• WAL サイズ (MB)

sqlite_wal_bytes / 1e6

• Log Level Heatmap (Loki)
  Query: {job="mmbot", level=~"(WARNING|ERROR)"}

6-6. Alertmanager ルール（例）

groups:
- name: mmbot
  rules:
  - alert: SharpDrop
    expr: mmbot_ev_usd < -20
    for: 5m
    annotations:
      summary: "PnL -$20 in 5m"
  - alert: WalBloated
    expr: sqlite_wal_bytes > 2e7
    for: 2m
    labels:
      severity: warning

Slack への通知 webhook は CI ですでに登録済みなので
“📉 SharpDrop” が飛べば即 Stop-Loss を手動介入するか、Bot を一時停止。

6-7. 5 分で導入する docker-compose.override.yml

services:
  promtail:
    image: grafana/promtail:2.9.0
    volumes:
      - ../promtail-config.yml:/etc/promtail/config.yml
      - ../runtime/${ENV}/logs:/app/data/logs:ro

  sqlite_exporter:
    build: infra/metrics/sqlite_exporter
    volumes:
      - ../runtime/${ENV}/db:/app/data/db:ro
    ports: ["9109:9109"]

1. docker compose up -d promtail sqlite_exporter
2. Grafana → Import infra/grafana/dashboards/mmbot.json
3. すぐに PnL と WAL が動き出す

6-8. “見える化” で得た即効改善ネタ

可視化→閾値調整→即反映、DevOps ループが “回っている” 実感 が爆増します。

6-9. ここまでで完成した “観測＆警戒” エコシステム

• Bot 死亡 → watchdog Slack
• 損失急増 → Prometheus Alert SharpDrop
• DB 肥大 → Alert WalBloated
• 戦略の勝ち／負け内訳 → Grafana “Result Tag Pie”

守り・攻め・評価を ダッシュボード 1 枚 に凝縮
→ 深夜 1 時のスマホ通知だけで異常を把握 → ほぼ放置運用へ。

これで “ログと DB をどう扱うか” の設計〜運用まで一気通貫。
最終まとめでは、今回の学びを 3 行の鉄則 に凝縮して締めくくります。

7. 失敗パターン集 ─ 「ログ肥大・DB 破損・権限エラー」 はこう起こる

覚え方：Storage 三重苦

1. サイズ (肥大) 2. ロック (破損) 3. パーミッション (読めない)

7-1. “DB 破損” が起こる典型シーケンス

flowchart TD
    WS["WS disconnect"] --> Retry["Bot busy-loop RETRY"]
    Retry --> Insert["大量 INSERT (約 500 rows/sec)"]
    Insert --> WalGrow["WAL 200 MB 突破"]
    WalGrow --> Restart["Docker 再起動 (自動更新)"]
    Restart --> SyncFail["WAL と DB の同期失敗"]
    SyncFail --> Locked["database is locked"]

教訓：

• WAL を 100 MB 超で警告 → trim_db.sh が 2 GB 爆発を未然に防ぐ
• Bot 再起動は WAL チェックポイント後 に行う

7-2. 手順書：破損 DB を 1 分で復旧

# 1. Bot 停止
docker compose stop mmbot

# 2. 最新 ZIP を戻す
cd runtime/production/db_backup
latest=$(ls -t pnl_*.zip | head -1)
unzip -o "$latest" -d ../db

# 3. WAL チェックポイント
sqlite3 ../db/pnl.db "PRAGMA wal_checkpoint(RESTART);"

# 4. 起動
docker compose start mmbot

備考：復旧 ZIP は VACUUM INTO 作成 なので WAL 不要。
運用中に最悪 DB を吹き飛ばしても Bot 再稼動 ≤ 60 sec。

8. 運用 Tips ─ ローカル・CI・本番を同一パスに揃えるベストプラクティス

ルールは 1 行：

“どの環境でも /app/data の実体は runtime/<env> であること”

8-1. CI で “Mounts denied” を 0 にするワンライナー

run: |
  docker compose config | grep runtime
  test $(docker compose config | grep -c "runtime") -eq 2

ブロークン PR は CI で即赤→ 本番事故ゼロ。

9. まとめ ─ ログと DB を分け、固定パスにし、Bot を守る 3 行の鉄則

1. runtime/<env>/{logs,db} 以外に書かせない
2. Loguru rotation (10 MB / 30 d) + SQLite WAL + 日次 VACUUM
3. メトリクスで “容量・ロック・ドローダウン” を常時監視

この 3 行を守れば “ストレージ絡みで Bot が止まる事故” は 99 % 消える。
あとは 戦略ロジック と 資金管理 に全リソースを投入して、
FRMMbot を ひたすら育てる フェーズに集中できます。