diff --git a/.agent/rules/documents.md b/.agent/rules/documents.md index 9902ebf..48e4d47 100644 --- a/.agent/rules/documents.md +++ b/.agent/rules/documents.md @@ -9,3 +9,4 @@ 3. ソースコードの編集が完了したら、`tools/count_loc.cjs` と `tools/nesting_depth.cjs` を使用して計測を行うこと。 4. 計測の結果、ソースコードが600行以上、またはネストが7階層以上のコードについては、リファクタリングを検討すること。 +5. コミットする前にジャーナルを書くこと。 diff --git "a/journals/20260304-0001-\343\203\226\343\203\274\343\203\210\343\203\255\343\202\260\343\201\250\351\226\213\347\231\272\350\265\267\345\213\225\343\201\256\346\224\271\345\226\204.md" "b/journals/20260304-0001-\343\203\226\343\203\274\343\203\210\343\203\255\343\202\260\343\201\250\351\226\213\347\231\272\350\265\267\345\213\225\343\201\256\346\224\271\345\226\204.md" new file mode 100644 index 0000000..58a279b --- /dev/null +++ "b/journals/20260304-0001-\343\203\226\343\203\274\343\203\210\343\203\255\343\202\260\343\201\250\351\226\213\347\231\272\350\265\267\345\213\225\343\201\256\346\224\271\345\226\204.md" @@ -0,0 +1,40 @@ +# 2026-03-04: ブートログの充実と開発起動の安定化 + +## 1. 作業の理由と意図 + +- **背景**: 起動時のログが簡素で、どこで時間がかかっているか分かりにくかった。また開発時(`npx tauri dev`)にウィンドウが「127.0.0.1 の応答に時間がかかりすぎました」(ERR_CONNECTION_TIMED_OUT)となり、フロントが表示されない事象があった。 +- **意図**: ブートシーケンスにフェーズ名と経過時間を出して観察しやすくする。開発時はフロント用サーバーを先に起動し、応答を待ってからウィンドウを開くようにしてタイムアウトを防ぐ。 + +## 2. 実施した変更 + +### ブートログの充実(lib.rs, mcp/mod.rs, mcp/system.rs) + +- **lib.rs**: 起動開始時に `Instant` を取得し、各フェーズで経過ミリ秒を出力。 + - `[BOOT] Phase 1: Paths resolved (Xms)` + - `[BOOT] Phase 2: vec0.dll ready (Xms)` + - `[BOOT] Phase 3: Tray icon ready (Xms)` + - `[BOOT] Phase 4: Initializing database...` → `Phase 4: Database ready (LSA-mode) (Xms)` + - `[BOOT] Phase 5: Starting MCP server on 127.0.0.1:3001 ...` + - `[BOOT] Setup complete (Xms). Window ready; MCP and LSA/HNSW continue in background.` +- **mcp/mod.rs**: `[BOOT] MCP: run_server started`、`LSA/HNSW background task spawned (Xms)`、`Listening on 127.0.0.1:3001 (Xms) — ready for connections`。MCP 受信ログを「MCP 受信」から「MCP receive」に変更(ログ文字化け防止)。 +- **mcp/system.rs**: LSA/HNSW の各段階に `[BOOT] LSA:` / `[BOOT] HNSW:` と経過時間を付与。`LSA+HNSW: all done (Xms)` を追加。 + +### 開発起動の安定化(tauri.conf.json, package.json) + +- **tauri.conf.json**: `build` に `devUrl: "http://127.0.0.1:1474"` と `beforeDevCommand: "npm run dev:frontend"` を追加。 +- **package.json**: `dev:frontend` スクリプト(`npx --yes serve src/frontend -l 1474`)を追加。 +- これにより、Tauri が先にフロント用サーバーを起動し、1474 に応答があるまで待ってから `cargo run` でウィンドウを開くため、ウィンドウ表示時の接続タイムアウトを回避。 + +### ルール追加 + +- **.agent/rules/documents.md**: 「5. コミットする前にジャーナルを書くこと。」を追加。 + +## 3. 観察結果(起動ログ例) + +- Tauri Setup: 約 92ms でウィンドウ準備完了。 +- MCP: 約 1208ms で 127.0.0.1:3001 で待ち受け開始。 +- LSA(20 文書): 約 9722ms。HNSW 含め LSA+HNSW 完了は約 9725ms。 + +## 4. その他 + +- `model_path` 未使用の警告は未修正(意図的な残置のため)。 diff --git a/package.json b/package.json index 2f4d5e2..a477b1f 100644 --- a/package.json +++ b/package.json @@ -5,6 +5,7 @@ "type": "module", "scripts": { "tauri": "tauri", + "dev:frontend": "npx --yes serve src/frontend -l 1474", "copy-editor": "node tools/copy-toast-ui-editor.js", "build-editor": "vite build --config tools/vite.config.editor.mjs" }, diff --git a/src/backend/src/lib.rs b/src/backend/src/lib.rs index 5577b89..be63e98 100644 --- a/src/backend/src/lib.rs +++ b/src/backend/src/lib.rs @@ -18,7 +18,8 @@ let default = serde_json::json!({ "min_score": 0.3, "limit": 10, - "run_on_login": false + "run_on_login": false, + "monitor_paths": [] }); if !path.exists() { log::info!("get_app_settings: no file at {:?}, returning default", path); @@ -35,10 +36,15 @@ .or(def.get("run_on_login")) .and_then(|v| v.as_bool().or_else(|| v.as_i64().map(|n| n != 0))) .unwrap_or(false); + let monitor_paths = obj.get("monitor_paths") + .and_then(|v| v.as_array()) + .cloned() + .unwrap_or_else(|| vec![]); let merged = serde_json::json!({ "min_score": obj.get("min_score").or(def.get("min_score")).unwrap_or(&serde_json::json!(0.3)), "limit": obj.get("limit").or(def.get("limit")).unwrap_or(&serde_json::json!(10)), - "run_on_login": run_on_login + "run_on_login": run_on_login, + "monitor_paths": monitor_paths }); log::info!("get_app_settings: returning run_on_login={}", run_on_login); Ok(merged) @@ -50,7 +56,7 @@ let dir = app.path().app_data_dir().map_err(|e| e.to_string())?; std::fs::create_dir_all(&dir).map_err(|e| e.to_string())?; let path = dir.join("settings.json"); - let to_write = if settings.get("min_score").is_some() || settings.get("run_on_login").is_some() { + let to_write = if settings.get("min_score").is_some() || settings.get("run_on_login").is_some() || settings.get("monitor_paths").is_some() { settings.clone() } else if let Some(inner) = settings.get("settings").and_then(|v| v.as_object()) { serde_json::to_value(inner).unwrap_or(settings) @@ -184,6 +190,8 @@ .setup({ let llama_child = llama_child.clone(); move |app| { + let boot_start = std::time::Instant::now(); + // Resolve paths let app_data_dir = app .path() @@ -191,13 +199,13 @@ .expect("failed to get app data dir"); let db_path = app_data_dir.join("telos.db"); - // llama-serverの起動をTauriのsidecar APIで行う let resource_dir = app.path().resource_dir().unwrap_or_default(); let bin_dir = resource_dir.join("bin"); let model_path = bin_dir.join("gemma-3-270m-it-Q4_K_M.gguf"); let exe_dir = std::env::current_exe().ok().and_then(|p| p.parent().map(|p| p.to_path_buf())); - log::info!("resource_dir: {:?}, exe_dir: {:?}", resource_dir, exe_dir); + log::info!("[BOOT] Phase 1: Paths resolved ({}ms)", boot_start.elapsed().as_millis()); + log::info!(" resource_dir: {:?}, exe_dir: {:?}", resource_dir, exe_dir); // vec0.dll: バンドル時は resources、開発時は exe 同階層。見つかったら app_data にコピーしてそこから読む let mut vec0_path: PathBuf = app @@ -229,13 +237,14 @@ if let Err(e) = std::fs::copy(&vec0_path, &vec0_in_app_data) { log::warn!("Failed to copy vec0.dll to app data: {}", e); } else { - log::info!("Copied vec0.dll to {:?}", vec0_in_app_data); + log::info!(" Copied vec0.dll to app_data"); } } if vec0_in_app_data.exists() { vec0_path = vec0_in_app_data; } } + log::info!("[BOOT] Phase 2: vec0.dll ready at {:?} ({}ms)", vec0_path, boot_start.elapsed().as_millis()); // Tray Menu let quit_i = MenuItem::with_id(app, "quit", "終了", true, None::<&str>)?; @@ -295,10 +304,7 @@ }) .build(app)?; - log::info!("Initializing TelosDB at {:?}", db_path); - log::info!("Bin directory: {:?}", bin_dir); - log::info!("Model path (Gemma-3): {:?}", model_path); - log::info!("vec0.dll path: {:?}", vec0_path); + log::info!("[BOOT] Phase 3: Tray icon ready ({}ms)", boot_start.elapsed().as_millis()); if !vec0_path.exists() { let msg = format!( @@ -348,12 +354,12 @@ } */ - // DB初期化とマネージドステートの設定 + log::info!("[BOOT] Phase 4: Initializing database at {:?} ...", db_path); let pool = tauri::async_runtime::block_on(async { let dimension = 50; // LSA のランクに合わせて 50次元に設定 match db::initialize_database(&db_path, &vec0_path, dimension).await { Ok(pool) => { - log::info!("Database initialized (LSA-mode)."); + log::info!("[BOOT] Phase 4: Database ready (LSA-mode) ({}ms)", boot_start.elapsed().as_millis()); pool } Err(e) => { @@ -367,7 +373,7 @@ db_pool: pool.clone(), }); - // MCP Server 起動 (llama_status は stopped 固定) + log::info!("[BOOT] Phase 5: Starting MCP server on 127.0.0.1:3001 ..."); use tokio::sync::RwLock; let llama_status = Arc::new(RwLock::new("stopped".to_string())); tauri::async_runtime::spawn({ @@ -377,6 +383,7 @@ } }); + log::info!("[BOOT] Setup complete ({}ms). Window ready; MCP and LSA/HNSW continue in background.", boot_start.elapsed().as_millis()); Ok(()) } }) diff --git a/src/backend/src/mcp/mod.rs b/src/backend/src/mcp/mod.rs index d9b2f5c..dac4403 100644 --- a/src/backend/src/mcp/mod.rs +++ b/src/backend/src/mcp/mod.rs @@ -40,9 +40,12 @@ llama_status: Arc>, model_name: String, ) { + let mcp_start = std::time::Instant::now(); + log::info!("[BOOT] MCP: run_server started (port={})", port); + let (tx, _rx) = broadcast::channel(100); let tokenizer = Arc::new(crate::utils::tokenizer::JapaneseTokenizer::new().unwrap()); - + let state = AppState { app_data_dir, db_pool, @@ -58,17 +61,18 @@ indexing_status: Arc::new(RwLock::new("idle".to_string())), }; - // 初期化時に LSA トレーニングとベクトル同期(HNSW構築含む)をバックグラウンドで開始 let state_init = state.clone(); tokio::spawn(async move { system::train_lsa_and_sync_hnsw(state_init).await; }); + log::info!("[BOOT] MCP: LSA/HNSW background task spawned ({}ms)", mcp_start.elapsed().as_millis()); let app = create_mcp_app(state); - let listener = tokio::net::TcpListener::bind(format!("127.0.0.1:{}", port)) + let bind_addr = format!("127.0.0.1:{}", port); + let listener = tokio::net::TcpListener::bind(&bind_addr) .await .unwrap(); - log::info!("MCP Server listening on {}", listener.local_addr().unwrap()); + log::info!("[BOOT] MCP: Listening on {} ({}ms) — ready for connections", listener.local_addr().unwrap(), mcp_start.elapsed().as_millis()); axum::serve(listener, app).await.unwrap(); } @@ -90,7 +94,7 @@ ) -> Response { // 1. Raw body logging for diagnostics (サーバーコンソールに操作時の受信メッセージを出力) let body_str = String::from_utf8_lossy(&body); - log::info!("[server] MCP 受信: {}", body_str); + log::info!("[server] MCP receive: {}", body_str); // 2. Manual JSON parsing to avoid silent extraction errors let req: JsonRpcRequest = match serde_json::from_slice(&body) { diff --git a/src/backend/src/mcp/system.rs b/src/backend/src/mcp/system.rs index a0a5937..f6f3f66 100644 --- a/src/backend/src/mcp/system.rs +++ b/src/backend/src/mcp/system.rs @@ -7,26 +7,28 @@ use crate::utils::lsa::LsaModel; pub async fn train_lsa_and_sync_hnsw(state: AppState) { - log::info!("Starting LSA model training (Async Pre-fetch)..."); + let boot_start = std::time::Instant::now(); + log::info!("[BOOT] LSA: starting (fetching documents)"); { let mut st = state.indexing_status.write().await; *st = "training".to_string(); } let _ = state.tx.send("indexing:training".to_string()); - // 1. DBからデータを集める(I/O) let rows = match sqlx::query("SELECT content FROM items").fetch_all(&state.db_pool).await { - Ok(rows) if !rows.is_empty() => rows, + Ok(rows) if !rows.is_empty() => { + log::info!("[BOOT] LSA: fetched {} documents ({}ms)", rows.len(), boot_start.elapsed().as_millis()); + rows + } _ => { - log::info!("No documents found for LSA training."); + log::info!("[BOOT] LSA: no documents, skip ({}ms)", boot_start.elapsed().as_millis()); *state.indexing_status.write().await = "idle".to_string(); let _ = state.tx.send("indexing:idle".to_string()); return; } }; - // 2. 重い計算処理(CPU)を spawn_blocking に移譲 - log::info!("Offloading LSA training to blocking thread..."); + log::info!("[BOOT] LSA: training in blocking thread..."); let state_inner = state.clone(); let result = tokio::task::spawn_blocking(move || { let mut builder = crate::utils::lsa::TermDocumentMatrixBuilder::new(); @@ -46,10 +48,9 @@ let mut lsa = state.lsa_model.write().await; *lsa = Some((*model_arc).clone()); } - log::info!("LSA model trained successfully with {} documents.", doc_count); - - // HNSW インデックスの構築 - log::info!("Building HNSW index..."); + log::info!("[BOOT] LSA: trained {} documents ({}ms)", doc_count, boot_start.elapsed().as_millis()); + + log::info!("[BOOT] HNSW: building index..."); let hnsw: Hnsw<'static, f32, DistCosine> = Hnsw::new(16, doc_count.max(100), 16, 200, DistCosine {}); { @@ -60,9 +61,10 @@ sync_all_vectors(state.clone(), Some(hnsw)).await; *state.indexing_status.write().await = "idle".to_string(); let _ = state.tx.send("indexing:idle".to_string()); + log::info!("[BOOT] LSA+HNSW: all done ({}ms)", boot_start.elapsed().as_millis()); } Err(e) => { - log::error!("LSA training failed: {}", e); + log::error!("[BOOT] LSA: training failed: {} ({}ms)", e, boot_start.elapsed().as_millis()); *state.indexing_status.write().await = "idle".to_string(); let _ = state.tx.send("indexing:idle".to_string()); } @@ -71,7 +73,7 @@ /// DB 内の全アイテムをチェックし、ベクトルが欠落または異常(全て0)なものを補完する pub async fn sync_all_vectors(state: AppState, startup_hnsw: Option>) { - log::info!("Checking for missing or invalid vectors in vec_items..."); + log::info!("[BOOT] HNSW: checking vectors in vec_items..."); let rows = match sqlx::query( "SELECT i.id, i.content, @@ -111,7 +113,7 @@ } if !to_sync.is_empty() { - log::info!("Found {} items needing vector update. Processing in blocking thread...", to_sync.len()); + log::info!("[BOOT] HNSW: {} items need vector update, processing...", to_sync.len()); let lsa_guard = state.lsa_model.read().await; if let Some(model) = lsa_guard.as_ref() { @@ -167,17 +169,16 @@ count += 1; } } - log::info!("Successfully synchronized {} vectors.", count); + log::info!("[BOOT] HNSW: synchronized {} vectors.", count); } else { - log::warn!("LSA model not available for sync."); + log::warn!("[BOOT] HNSW: LSA model not available for sync."); } } else { - log::info!("All vectors are healthy and synchronized."); + log::info!("[BOOT] HNSW: all vectors healthy."); } - // HNSW インデックスを AppState に登録 if let Some(hnsw) = startup_hnsw { - log::info!("Populating HNSW index from database in blocking thread..."); + log::info!("[BOOT] HNSW: populating index from database..."); let db = state.db_pool.clone(); tokio::task::spawn_blocking(move || { @@ -202,7 +203,7 @@ } if !data_to_insert.is_empty() { - log::info!("Performing parallel HNSW insertion for {} items...", data_to_insert.len()); + log::info!("[BOOT] HNSW: inserting {} items...", data_to_insert.len()); tokio::task::spawn_blocking(move || { let refs: Vec<(&Vec, usize)> = data_to_insert.iter().map(|(v, id)| (v, *id)).collect(); hnsw.parallel_insert(&refs); @@ -211,13 +212,13 @@ tokio::spawn(async move { let mut idx = state_inner.hnsw_index.write().await; *idx = Some(hnsw_ready); - log::info!("HNSW index is now ready."); + log::info!("[BOOT] HNSW: index ready."); }); }).unwrap_or_else(|e| log::error!("HNSW parallel insert panicked: {}", e)); } else { let mut idx = state_inner.hnsw_index.write().await; *idx = Some(hnsw); - log::info!("HNSW index is ready (no items)."); + log::info!("[BOOT] HNSW: index ready (no items)."); } } }); diff --git a/src/backend/tauri.conf.json b/src/backend/tauri.conf.json index 12c704e..1dec81e 100644 --- a/src/backend/tauri.conf.json +++ b/src/backend/tauri.conf.json @@ -3,7 +3,11 @@ "productName": "TelosDB", "version": "0.3.2", "identifier": "com.telosdb.app", - "build": { "frontendDist": "../frontend" }, + "build": { + "frontendDist": "../frontend", + "devUrl": "http://127.0.0.1:1474", + "beforeDevCommand": "npm run dev:frontend" + }, "app": { "windows": [{ "title": "TelosDB", "width": 800, "height": 600, "resizable": true, "fullscreen": false }], "security": { "csp": null },