fix: 画像生成モデルのロードを初回生成まで遅延するHEADmain

stdio MCPのツール一覧取得でも、受付開始前にModelManagerがSD本体・
外部VAE・LoRAをロードし、CUDAへ転送していた。画像生成しない通常の
質問でもこの起動コストが発生するため、有効な生成要求の実行時まで
モデル初期化を遅らせ、一覧取得時の不要な遅延とVRAM消費を除去する。

実装:
- ModelManagerの構築時は未ロード状態とし、冪等なload()を追加する。
- 初期化ロックで二重ロードを防ぎ、成功時だけモデルを保持する。
  失敗時は未ロード状態を維持し、次の要求で再試行できるようにする。
- 3種類の生成メソッドからload()を呼び、既存サービスの入力検証・
  生成ロックを経由したワーカースレッド内で初期化する。
- ControlNetと前処理モデルの既存の遅延ロード・モデル共有を維持する。
- 起動・設定読み込みと実際のモデルロードのログを分離し、ロードの
  開始・完了・失敗をstderrへ出力する。
- benchmarkの計測区間で明示的にload()を呼び、ロード時間とVRAMの
  計測の意味を維持する。READMEにロードタイミングと確認手順を追記する。

変更範囲:
- stdioのプロセス起動・終了方式を維持し、常駐化やHTTP切り替え、
  チャット側の接続管理・一覧キャッシュ・アイドル解放は追加しない。
- MCPスキーマ、設定形式、CLI引数、プロンプト・seed処理、scheduler、
  生成サイズ、PNGメタデータ・保存仕様は変更しない。
- 設定とモデルファイルの存在確認は起動時に残し、モデル互換性・
  CUDA・推論依存関係のエラー検出は初回生成時へ移す。
- 同一プロセス内ではモデルを再利用し、終了時に解放する。
  別の生成プロセスでの再ロードは引き続き許容する。

回帰テスト:
- 修正前の既存69件に対し、修正後は追加18件を含む87件すべて成功。
  既存テストと期待値は変更していない。
- CLI/stdioでの一覧取得時にモデルロードと推論ライブラリのimportを
  禁止しても成功することを確認する。
- 全生成方式の初回ロード、ワーカースレッド実行、同時要求、冪等性、
  不正入力・無効なControlNet指定、失敗後の再試行、ログを検証する。
- ruff check .は成功、pyrightは0 errors / 0 warnings。

実GPU・stdioでの確認:
- 現在の設定（外部VAE、2件のLoRA、LCM、6 steps）を維持して計測した。
- 起動から一覧取得までの時間は8.233秒から0.671秒に短縮した。
- 一覧取得前後のGPU全体の使用量は修正前808→3233 MiBに対し、
  修正後682→682 MiBで増加しなかった。
- 同じ接続で2枚生成してもベースモデルのロードは1回で、一覧取得では
  0回だった。ロード時間は7.812秒で、初回生成要求に移った。
- 同じ設定・プロンプト・seedによる修正前後の画像は画素が完全一致。
  PNG形式・寸法・メタデータと、返却PNGおよび保存PNGの一致を確認した。
- 最終版スクリプトでの再確認でも一覧取得0.655秒、初回生成14.089秒、
  2枚目1.221秒で、画素・保存結果の一致と生成プロセス終了を確認した。
- 通常質問の親アプリの処理経路でも、LLMのみをスタブ化し、実際の
  設定済みuvコマンドで一覧取得・3ツールの登録を確認した。
- 計測スクリプトと詳細な検証報告を追加する。生のJSON・stderr・PNGは
  gitignore対象のdata/verification-lazy-loadに保存する。

確認の限界:
- Windowsのプロセス別VRAMはN/Aのため、GPU全体の使用量・プロセス一覧・
  tasklistによる終了確認で評価した。全体値には他プロセスの変動がある。
- 計測値は単一セッションの観測であり、統計的な速度保証ではない。
- ブラウザ操作と実LLMを含むチャット全体、および現在の設定で無効な
  ControlNetの実GPU生成は未実施。誘導生成・Inpaintのロード順は
  スタブを用いた自動テストで確認した。

2 files changed, 36 insertions, 3 deletions

diff --git a/src/mcp_sd15/cli.py b/src/mcp_sd15/cli.py
index abfde01..1248581 100644
--- a/src/mcp_sd15/cli.py
+++ b/src/mcp_sd15/cli.py
@@ -31,13 +31,14 @@ def main(argv: Sequence[str] | None = None) -> int:
     try:
         config = load_config(args.config)
         logging.getLogger(__name__).info(
-            "loading checkpoint=%s loras=%d",
+            "configuration loaded checkpoint=%s loras=%d; models load on generation",
             config.model.checkpoint_path(),
             len(config.model.loras),
         )
         backend = ModelManager(config)
         service = ImageGenerationService(config, backend)
         server = create_server(service)
+        logging.getLogger(__name__).info("starting MCP transport=%s", config.server.transport)
         if config.server.transport == "streamable-http":
             server.run(
                 transport="streamable-http",
diff --git a/src/mcp_sd15/model_manager.py b/src/mcp_sd15/model_manager.py
index e87a813..2c314d1 100644
--- a/src/mcp_sd15/model_manager.py
+++ b/src/mcp_sd15/model_manager.py
@@ -3,6 +3,9 @@
 from __future__ import annotations
 
 import gc
+import logging
+import threading
+import time
 from typing import Any
 
 import numpy as np
@@ -15,21 +18,48 @@ from .preprocessors.depth import DepthPreprocessor
 from .preprocessors.openpose import OpenPosePreprocessor
 from .schema import GuidedImageRequest, InpaintImageRequest, TextToImageRequest
 
+logger = logging.getLogger(__name__)
+
 
 class ModelManager:
-    """Own all model state; construction validates model compatibility at startup."""
+    """Own model state, loading inference models only when generation needs them."""
 
     def __init__(self, config: AppConfig) -> None:
         self.config = config
         self.factory = PipelineFactory(config)
-        self.base = self.factory.create_base()
+        self.base: Any = None
+        self._load_lock = threading.Lock()
         self._control_mode: str | None = None
         self._controlnet: Any | None = None
         self._control_pipeline: Any | None = None
         self._depth = DepthPreprocessor()
         self._openpose = OpenPosePreprocessor()
 
+    def load(self) -> None:
+        """Load once on success; failed initialization remains retryable.
+
+        Generation calls this from the service's serialized worker thread.
+        The lock also protects explicit loads by measurement scripts.
+        """
+        with self._load_lock:
+            if self.base is not None:
+                return
+            started = time.monotonic()
+            logger.info(
+                "model load started checkpoint=%s loras=%d",
+                self.config.model.checkpoint_path(),
+                len(self.config.model.loras),
+            )
+            try:
+                base = self.factory.create_base()
+            except Exception:
+                logger.exception("model load failed")
+                raise
+            self.base = base
+            logger.info("model load completed elapsed_seconds=%.3f", time.monotonic() - started)
+
     def text_to_image(self, request: TextToImageRequest, seed: int) -> Image.Image:
+        self.load()
         width, height = request.size.dimensions
         prompt_embeds, negative_prompt_embeds = self._embed_prompts(
             request.positive_prompt, request.negative_prompt
@@ -49,6 +79,7 @@ class ModelManager:
     def guided_image(
         self, request: GuidedImageRequest, image: Image.Image, seed: int
     ) -> Image.Image:
+        self.load()
         width, height = request.size.dimensions
         image = image.resize((width, height), Image.Resampling.LANCZOS)
         if request.control_mode == "depth":
@@ -79,6 +110,7 @@ class ModelManager:
         mask: Image.Image,
         seed: int,
     ) -> Image.Image:
+        self.load()
         width, height = request.size.dimensions
         image = image.resize((width, height), Image.Resampling.LANCZOS)
         mask = mask.resize((width, height), Image.Resampling.NEAREST)