diff --git a/src/auto_task/app_generator.rs b/src/auto_task/app_generator.rs index bc101e4cd..7dbc7290f 100644 --- a/src/auto_task/app_generator.rs +++ b/src/auto_task/app_generator.rs @@ -1015,7 +1015,7 @@ impl AppGenerator { }; // Mark "Analyzing Request" as completed - info!("[PHASE1->2] Marking Analyzing Request as Completed"); + info!(" Marking Analyzing Request as Completed"); self.update_manifest_section(SectionType::Validation, SectionStatus::Completed); self.broadcast_manifest_update(); @@ -1069,7 +1069,7 @@ impl AppGenerator { let tables = Self::convert_llm_tables(&llm_app.tables); if !tables.is_empty() { - info!("[PHASE2] Setting Database & Models section to Running"); + info!(" Setting Database & Models section to Running"); self.update_manifest_section(SectionType::DatabaseModels, SectionStatus::Running); self.broadcast_manifest_update(); self.update_manifest_child( @@ -1282,7 +1282,7 @@ impl AppGenerator { // Debug: List all sections before update if let Some(ref manifest) = self.manifest { - info!("[PHASE2B] Current manifest sections:"); + info!(" Current manifest sections:"); for (i, s) in manifest.sections.iter().enumerate() { info!( "[PHASE2B] [{}] {:?} = '{}' status={:?}", @@ -1301,7 +1301,7 @@ impl AppGenerator { for idx in files_needing_content { let filename = llm_app.files[idx].filename.clone(); generated_count += 1; - info!("[PHASE2B] Starting generation for file: {}", filename); + info!(" Starting generation for file: {}", filename); self.add_terminal_output( &format!("Generating `{filename}`..."), TerminalLineType::Info, @@ -1783,11 +1783,11 @@ impl AppGenerator { match std::fs::read_to_string(&prompt_path) { Ok(content) => { - info!("[APP_GENERATOR] Loaded prompt from {:?} ({} chars)", prompt_path, content.len()); + info!("Loaded prompt from {:?} ({} chars)", prompt_path, content.len()); content } Err(e) => { - warn!("[APP_GENERATOR] Failed to load APP_GENERATOR_PROMPT.md: {}, using fallback", e); + warn!("Failed to load APP_GENERATOR_PROMPT.md: {}, using fallback", e); Self::get_fallback_prompt().to_string() } } @@ -1876,7 +1876,7 @@ RESPOND ONLY WITH THE PLAN STRUCTURE. NO QUESTIONS."# intent_preview ); let response = self.call_llm(&prompt, bot_id).await?; - info!("[PHASE1] Project plan received, parsing..."); + info!(" Project plan received, parsing..."); Self::parse_project_plan(&response, intent) } @@ -1894,7 +1894,7 @@ RESPOND ONLY WITH THE PLAN STRUCTURE. NO QUESTIONS."# "[PHASE1_PARSE] Response preview: {}", response_preview.replace('\n', "\\n") ); - info!("[PHASE1_PARSE] Has APP_START: {}, Has TABLES_START: {}, Has FILES_PLAN: {}, Has TOOLS_PLAN: {}", + trace!(" Has APP_START: {}, Has TABLES_START: {}, Has FILES_PLAN: {}, Has TOOLS_PLAN: {}", response.contains("<<>>"), response.contains("<<>>"), response.contains("<<>>"), @@ -1976,7 +1976,7 @@ RESPOND ONLY WITH THE PLAN STRUCTURE. NO QUESTIONS."# } } } else { - info!("[PHASE1_PARSE] TABLES_START not found, trying <<>> delimiters..."); + trace!(" TABLES_START not found, trying <<>> delimiters..."); for table_match in response.match_indices("<<>> delimiters..."); + trace!(" TOOLS_PLAN not found, trying <<>> delimiters..."); for tool_match in response.match_indices("<< { @@ -382,10 +382,10 @@ pub async fn create_and_execute_handler( } }); - info!("[AUTOTASK] Spawn result: {:?}", spawn_result); + info!(" Spawn result: {:?}", spawn_result); // Return immediately with task_id - client will poll for status - info!("[AUTOTASK] Returning immediately with task_id={}", task_id); + info!(" Returning immediately with task_id={}", task_id); ( StatusCode::ACCEPTED, Json(CreateAndExecuteResponse { diff --git a/src/auto_task/intent_classifier.rs b/src/auto_task/intent_classifier.rs index d34ebf72e..26be8a312 100644 --- a/src/auto_task/intent_classifier.rs +++ b/src/auto_task/intent_classifier.rs @@ -281,12 +281,12 @@ Respond with JSON only: }}"# ); - info!("[INTENT_CLASSIFIER] Starting LLM call for classification, prompt_len={} chars", prompt.len()); + info!("Starting LLM call for classification, prompt_len={} chars", prompt.len()); let start = std::time::Instant::now(); let response = self.call_llm(&prompt, bot_id).await?; let elapsed = start.elapsed(); - info!("[INTENT_CLASSIFIER] LLM classification completed in {:?}, response_len={} chars", elapsed, response.len()); + info!("LLM classification completed in {:?}, response_len={} chars", elapsed, response.len()); trace!("LLM classification response: {}", &response[..response.len().min(500)]); Self::parse_classification_response(&response, intent) } diff --git a/src/auto_task/mod.rs b/src/auto_task/mod.rs index 024558f34..d950ab501 100644 --- a/src/auto_task/mod.rs +++ b/src/auto_task/mod.rs @@ -179,17 +179,17 @@ async fn handle_task_progress_websocket( match sender.send(Message::Text(json_str)).await { Ok(()) => { if is_manifest { - info!("[WS_HANDLER] manifest_update SENT successfully to WebSocket"); + info!("manifest_update SENT successfully to WebSocket"); } } Err(e) => { - error!("[WS_HANDLER] Failed to send to WebSocket: {:?}", e); + error!("Failed to send to WebSocket: {:?}", e); break; } } } Err(e) => { - error!("[WS_HANDLER] Failed to serialize event: {:?}", e); + error!("Failed to serialize event: {:?}", e); } } } diff --git a/src/basic/compiler/blocks/mail.rs b/src/basic/compiler/blocks/mail.rs index 5a1f77d03..23d07d22d 100644 --- a/src/basic/compiler/blocks/mail.rs +++ b/src/basic/compiler/blocks/mail.rs @@ -68,7 +68,7 @@ pub fn convert_mail_line_with_substitution(line: &str) -> String { } } - info!("[TOOL] Converted mail line: '{}' → '{}'", line, result); + info!("Converted mail line: '{}' → '{}'", line, result); result } @@ -138,6 +138,6 @@ pub fn convert_mail_block(recipient: &str, lines: &[String]) -> String { }; result.push_str(&format!("send_mail({}, \"{}\", {}, []);\n", recipient_expr, subject, body_expr)); - info!("[TOOL] Converted MAIL block → {}", result); + info!("Converted MAIL block → {}", result); result } diff --git a/src/basic/compiler/blocks/mod.rs b/src/basic/compiler/blocks/mod.rs index ade887152..5f7f21c6f 100644 --- a/src/basic/compiler/blocks/mod.rs +++ b/src/basic/compiler/blocks/mod.rs @@ -23,14 +23,14 @@ pub fn convert_begin_blocks(script: &str) -> String { } if upper == "BEGIN TALK" { - info!("[TOOL] Converting BEGIN TALK statement"); + info!("Converting BEGIN TALK statement"); in_talk_block = true; talk_block_lines.clear(); continue; } if upper == "END TALK" { - info!("[TOOL] Converting END TALK statement, processing {} lines", talk_block_lines.len()); + info!("Converting END TALK statement, processing {} lines", talk_block_lines.len()); in_talk_block = false; let converted = convert_talk_block(&talk_block_lines); result.push_str(&converted); @@ -45,7 +45,7 @@ pub fn convert_begin_blocks(script: &str) -> String { if upper.starts_with("BEGIN MAIL ") { let recipient = &trimmed[11..].trim(); - info!("[TOOL] Converting BEGIN MAIL statement: recipient='{}'", recipient); + info!("Converting BEGIN MAIL statement: recipient='{}'", recipient); mail_recipient = recipient.to_string(); in_mail_block = true; mail_block_lines.clear(); @@ -53,7 +53,7 @@ pub fn convert_begin_blocks(script: &str) -> String { } if upper == "END MAIL" { - info!("[TOOL] Converting END MAIL statement, processing {} lines", mail_block_lines.len()); + info!("Converting END MAIL statement, processing {} lines", mail_block_lines.len()); in_mail_block = false; let converted = convert_mail_block(&mail_recipient, &mail_block_lines); result.push_str(&converted); diff --git a/src/basic/compiler/blocks/talk.rs b/src/basic/compiler/blocks/talk.rs index e51955362..2566f30eb 100644 --- a/src/basic/compiler/blocks/talk.rs +++ b/src/basic/compiler/blocks/talk.rs @@ -109,7 +109,7 @@ pub fn convert_talk_line_with_substitution(line: &str) -> String { result = "TALK \"\"".to_string(); } - info!("[TOOL] Converted TALK line: '{}' → '{}'", line, result); + info!("Converted TALK line: '{}' → '{}'", line, result); result } diff --git a/src/basic/compiler/mod.rs b/src/basic/compiler/mod.rs index 5540cd98e..9b4b7a739 100644 --- a/src/basic/compiler/mod.rs +++ b/src/basic/compiler/mod.rs @@ -676,7 +676,7 @@ impl BasicCompiler { let table_name = table_name.trim_matches('"'); // Debug log to see what we're querying - log::info!("[SAVE] Converting SAVE for table: '{}' (original: '{}')", table_name, &parts[0]); + log::info!("Converting SAVE for table: '{}' (original: '{}')", table_name, &parts[0]); // Get column names from TABLE definition (preserves order from .bas file) let column_names = self.get_table_columns_for_save(table_name, bot_id)?; @@ -685,7 +685,7 @@ impl BasicCompiler { let values: Vec<&String> = parts.iter().skip(1).collect(); let mut map_pairs = Vec::new(); - log::info!("[SAVE] Matching {} variables to {} columns", values.len(), column_names.len()); + log::info!("Matching {} variables to {} columns", values.len(), column_names.len()); for value_var in values.iter() { // Find the column that matches this variable (case-insensitive) @@ -694,7 +694,7 @@ impl BasicCompiler { if let Some(column_name) = column_names.iter().find(|col| col.to_lowercase() == value_lower) { map_pairs.push(format!("{}: {}", column_name, value_var)); } else { - log::warn!("[SAVE] No matching column for variable '{}'", value_var); + log::warn!("No matching column for variable '{}'", value_var); } } diff --git a/src/basic/keywords/add_suggestion.rs b/src/basic/keywords/add_suggestion.rs index ac771e82a..c7b49e0f3 100644 --- a/src/basic/keywords/add_suggestion.rs +++ b/src/basic/keywords/add_suggestion.rs @@ -401,7 +401,7 @@ pub fn get_suggestions( } } info!( - "[SUGGESTIONS] Retrieved {} suggestions for session {}", + "Retrieved {} suggestions for session {}", suggestions.len(), session_id ); @@ -413,7 +413,7 @@ pub fn get_suggestions( // .arg(&redis_key) // .query(&mut conn); // info!( - // "[SUGGESTIONS] Cleared {} suggestions from Redis for session {}", + // "Cleared {} suggestions from Redis for session {}", // suggestions.len(), // session_id // ); @@ -422,7 +422,7 @@ pub fn get_suggestions( Err(e) => error!("Failed to get suggestions from Redis: {}", e), } } else { - info!("[SUGGESTIONS] No cache configured, cannot retrieve suggestions"); + info!("No cache configured, cannot retrieve suggestions"); } suggestions diff --git a/src/basic/keywords/use_tool.rs b/src/basic/keywords/use_tool.rs index 7bc46ab85..51ef9c89d 100644 --- a/src/basic/keywords/use_tool.rs +++ b/src/basic/keywords/use_tool.rs @@ -198,21 +198,13 @@ fn associate_tool_with_session( tool_name: &str, ) -> Result { use crate::core::shared::models::schema::session_tool_associations; - use std::fs; // Check if tool's .mcp.json file exists in work directory - // Use relative path from botserver binary location + // Use relative path from botserver binary current directory let gb_dir = std::env::current_dir() .unwrap_or_else(|_| PathBuf::from(".")) .join("botserver-stack/data/system"); - // Ensure work directory exists (create if not) - let work_base = gb_dir.join("work"); - if !work_base.exists() { - fs::create_dir_all(&work_base).map_err(|e| format!("Failed to create work directory {:?}: {}", work_base, e))?; - info!("Created work directory at: {:?}", work_base); - } - // Get bot name to construct the path let bot_name = get_bot_name_from_id(state, &user.bot_id)?; let work_path = Path::new(&gb_dir) diff --git a/src/basic/mod.rs b/src/basic/mod.rs index 2dc0a9dfe..55419d550 100644 --- a/src/basic/mod.rs +++ b/src/basic/mod.rs @@ -587,7 +587,7 @@ impl ScriptService { .collect::>() .join("\n"); - info!("[TOOL] Filtered tool metadata: {} -> {} chars", script.len(), executable_script.len()); + info!("Filtered tool metadata: {} -> {} chars", script.len(), executable_script.len()); // Apply minimal preprocessing for tools (skip variable normalization to avoid breaking multi-line strings) let script = preprocess_switch(&executable_script); @@ -597,7 +597,7 @@ impl ScriptService { // let script = Self::convert_format_syntax(&script); // Skip normalize_variables_to_lowercase for tools - it breaks multi-line strings - info!("[TOOL] Preprocessed tool script for Rhai compilation"); + info!("Preprocessed tool script for Rhai compilation"); // Convert SAVE statements with field lists to map-based SAVE (simplified version for tools) let script = Self::convert_save_for_tools(&script); // Convert BEGIN TALK and BEGIN MAIL blocks to single calls @@ -986,7 +986,7 @@ impl ScriptService { }; result.push_str(&format!("send_mail({}, \"{}\", {}, []);\n", recipient_expr, subject, body_expr)); - log::info!("[TOOL] Converted MAIL block → {}", result); + log::info!("Converted MAIL block → {}", result); result } @@ -1086,7 +1086,7 @@ impl ScriptService { let mut mail_block_lines: Vec = Vec::new(); let mut in_line_continuation = false; - log::info!("[TOOL] Converting IF/THEN syntax, input has {} lines", script.lines().count()); + log::info!("Converting IF/THEN syntax, input has {} lines", script.lines().count()); for line in script.lines() { let trimmed = line.trim(); @@ -1119,7 +1119,7 @@ impl ScriptService { } else { condition.to_string() }; - log::info!("[TOOL] Converting IF statement: condition='{}'", condition); + log::info!("Converting IF statement: condition='{}'", condition); result.push_str("if "); result.push_str(&condition); result.push_str(" {\n"); @@ -1129,7 +1129,7 @@ impl ScriptService { // Handle ELSE if upper == "ELSE" { - log::info!("[TOOL] Converting ELSE statement"); + log::info!("Converting ELSE statement"); result.push_str("} else {\n"); continue; } @@ -1152,7 +1152,7 @@ impl ScriptService { } else { condition.to_string() }; - log::info!("[TOOL] Converting ELSEIF statement: condition='{}'", condition); + log::info!("Converting ELSEIF statement: condition='{}'", condition); result.push_str("} else if "); result.push_str(&condition); result.push_str(" {\n"); @@ -1161,7 +1161,7 @@ impl ScriptService { // Handle END IF if upper == "END IF" { - log::info!("[TOOL] Converting END IF statement"); + log::info!("Converting END IF statement"); if if_stack.pop().is_some() { result.push_str("}\n"); } @@ -1171,7 +1171,7 @@ impl ScriptService { // Handle WITH ... END WITH (BASIC object creation) if upper.starts_with("WITH ") { let object_name = &trimmed[5..].trim(); - log::info!("[TOOL] Converting WITH statement: object='{}'", object_name); + log::info!("Converting WITH statement: object='{}'", object_name); // Convert WITH obj → let obj = #{ (start object literal) result.push_str("let "); result.push_str(object_name); @@ -1181,7 +1181,7 @@ impl ScriptService { } if upper == "END WITH" { - log::info!("[TOOL] Converting END WITH statement"); + log::info!("Converting END WITH statement"); result.push_str("};\n"); in_with_block = false; continue; @@ -1189,14 +1189,14 @@ impl ScriptService { // Handle BEGIN TALK ... END TALK (multi-line TALK with ${} substitution) if upper == "BEGIN TALK" { - log::info!("[TOOL] Converting BEGIN TALK statement"); + log::info!("Converting BEGIN TALK statement"); in_talk_block = true; talk_block_lines.clear(); continue; } if upper == "END TALK" { - log::info!("[TOOL] Converting END TALK statement, processing {} lines", talk_block_lines.len()); + log::info!("Converting END TALK statement, processing {} lines", talk_block_lines.len()); in_talk_block = false; // Split into multiple TALK statements to avoid expression complexity limit @@ -1239,7 +1239,7 @@ impl ScriptService { // Handle BEGIN MAIL ... END MAIL (multi-line email with ${} substitution) if upper.starts_with("BEGIN MAIL ") { let recipient = &trimmed[11..].trim(); // Skip "BEGIN MAIL " - log::info!("[TOOL] Converting BEGIN MAIL statement: recipient='{}'", recipient); + log::info!("Converting BEGIN MAIL statement: recipient='{}'", recipient); mail_recipient = recipient.to_string(); in_mail_block = true; mail_block_lines.clear(); @@ -1247,7 +1247,7 @@ impl ScriptService { } if upper == "END MAIL" { - log::info!("[TOOL] Converting END MAIL statement, processing {} lines", mail_block_lines.len()); + log::info!("Converting END MAIL statement, processing {} lines", mail_block_lines.len()); in_mail_block = false; // Process the mail block and convert to SEND EMAIL @@ -1287,11 +1287,11 @@ impl ScriptService { // Handle SAVE table, field1, field2, ... → INSERT "table", #{field1: value1, field2: value2, ...} if upper.starts_with("SAVE") && upper.contains(',') { - log::info!("[TOOL] Processing SAVE line: '{}'", trimmed); + log::info!("Processing SAVE line: '{}'", trimmed); // Extract the part after "SAVE" let after_save = &trimmed[4..].trim(); // Skip "SAVE" let parts: Vec<&str> = after_save.split(',').collect(); - log::info!("[TOOL] SAVE parts: {:?}", parts); + log::info!("SAVE parts: {:?}", parts); if parts.len() >= 2 { // First part is the table name (in quotes) @@ -1301,7 +1301,7 @@ impl ScriptService { if parts.len() == 2 { let object_name = parts[1].trim().trim_end_matches(';'); let converted = format!("INSERT \"{}\", {};\n", table, object_name); - log::info!("[TOOL] Converted SAVE to INSERT (old syntax): '{}'", converted); + log::info!("Converted SAVE to INSERT (old syntax): '{}'", converted); result.push_str(&converted); continue; } @@ -1310,7 +1310,7 @@ impl ScriptService { // The runtime SAVE handler will match them to database columns by position let values = parts[1..].join(", "); let converted = format!("SAVE \"{}\", {};\n", table, values); - log::info!("[TOOL] Keeping SAVE syntax (modern): '{}'", converted); + log::info!("Keeping SAVE syntax (modern): '{}'", converted); result.push_str(&converted); continue; } @@ -1319,17 +1319,17 @@ impl ScriptService { // Handle SEND EMAIL → send_mail (function call style) // Syntax: SEND EMAIL to, subject, body → send_mail(to, subject, body, []) if upper.starts_with("SEND EMAIL") { - log::info!("[TOOL] Processing SEND EMAIL line: '{}'", trimmed); + log::info!("Processing SEND EMAIL line: '{}'", trimmed); let after_send = &trimmed[11..].trim(); // Skip "SEND EMAIL " (10 chars + space = 11) let parts: Vec<&str> = after_send.split(',').collect(); - log::info!("[TOOL] SEND EMAIL parts: {:?}", parts); + log::info!("SEND EMAIL parts: {:?}", parts); if parts.len() == 3 { let to = parts[0].trim(); let subject = parts[1].trim(); let body = parts[2].trim().trim_end_matches(';'); // Convert to send_mail(to, subject, body, []) function call let converted = format!("send_mail({}, {}, {}, []);\n", to, subject, body); - log::info!("[TOOL] Converted SEND EMAIL to: '{}'", converted); + log::info!("Converted SEND EMAIL to: '{}'", converted); result.push_str(&converted); continue; } @@ -1397,7 +1397,7 @@ impl ScriptService { } } - log::info!("[TOOL] IF/THEN conversion complete, output has {} lines", result.lines().count()); + log::info!("IF/THEN conversion complete, output has {} lines", result.lines().count()); // Convert BASIC <> (not equal) to Rhai != globally @@ -1417,7 +1417,7 @@ impl ScriptService { let lines: Vec<&str> = script.lines().collect(); let mut i = 0; - log::info!("[TOOL] Converting SELECT/CASE syntax to if-else chains"); + log::info!("Converting SELECT/CASE syntax to if-else chains"); // Helper function to strip 'let ' from the beginning of a line // This is needed because convert_if_then_syntax adds 'let' to all assignments, @@ -1441,7 +1441,7 @@ impl ScriptService { if upper.starts_with("SELECT ") && !upper.contains(" THEN") { // Extract the variable being selected let select_var = trimmed[7..].trim(); // Skip "SELECT " - log::info!("[TOOL] Converting SELECT statement for variable: '{}'", select_var); + log::info!("Converting SELECT statement for variable: '{}'", select_var); // Skip the SELECT line i += 1; diff --git a/src/core/bot/mod.rs b/src/core/bot/mod.rs index 3e3cc0221..46bed978b 100644 --- a/src/core/bot/mod.rs +++ b/src/core/bot/mod.rs @@ -440,9 +440,6 @@ impl BotOrchestrator { let config_manager = ConfigManager::new(state_clone.conn.clone()); - // DEBUG: Log which bot we're getting config for - info!("[CONFIG_TRACE] Getting LLM config for bot_id: {}", session.bot_id); - // For local LLM server, use the actual model name // Default to DeepSeek model if not configured let model = config_manager @@ -453,12 +450,6 @@ impl BotOrchestrator { .get_config(&session.bot_id, "llm-key", Some("")) .unwrap_or_default(); - // DEBUG: Log the exact config values retrieved - info!("[CONFIG_TRACE] Model: '{}'", model); - info!("[CONFIG_TRACE] API Key: '{}' ({} chars)", key, key.len()); - info!("[CONFIG_TRACE] API Key first 10 chars: '{}'", &key.chars().take(10).collect::()); - info!("[CONFIG_TRACE] API Key last 10 chars: '{}'", &key.chars().rev().take(10).collect::()); - Ok((session, context_data, history, model, key)) }, ) @@ -508,12 +499,10 @@ impl BotOrchestrator { let data_dir = "/opt/gbo/data"; let start_script_path = format!("{}/{}.gbai/{}.gbdialog/start.bas", data_dir, bot_name_for_context, bot_name_for_context); - info!("[START_BAS] Executing start.bas for session {} at: {}", actual_session_id, start_script_path); + trace!("Executing start.bas for session {} at: {}", actual_session_id, start_script_path); if let Ok(metadata) = tokio::fs::metadata(&start_script_path).await { if metadata.is_file() { - info!("[START_BAS] Found start.bas, executing for session {}", actual_session_id); - if let Ok(start_script) = tokio::fs::read_to_string(&start_script_path).await { let state_clone = self.state.clone(); let actual_session_id_for_task = session.id; @@ -551,7 +540,7 @@ impl BotOrchestrator { match result { Ok(Ok(())) => { - info!("[START_BAS] start.bas completed successfully for session {}", actual_session_id); + trace!("start.bas completed successfully for session {}", actual_session_id); // Mark start.bas as executed for this session to prevent re-running if let Some(cache) = &self.state.cache { @@ -563,15 +552,14 @@ impl BotOrchestrator { .arg("86400") // Expire after 24 hours .query_async(&mut conn) .await; - info!("[START_BAS] Marked start.bas as executed for session {}", actual_session_id); } } } Ok(Err(e)) => { - error!("[START_BAS] start.bas error for session {}: {}", actual_session_id, e); + error!("start.bas error for session {}: {}", actual_session_id, e); } Err(e) => { - error!("[START_BAS] start.bas task error for session {}: {}", actual_session_id, e); + error!("start.bas task error for session {}: {}", actual_session_id, e); } } } @@ -613,12 +601,7 @@ impl BotOrchestrator { })); } - // DEBUG: Log messages before sending to LLM - info!("[LLM_CALL] Messages before LLM: {}", serde_json::to_string_pretty(&messages).unwrap_or_default()); - info!("[LLM_CALL] message_content: '{}'", message_content); - let (stream_tx, mut stream_rx) = mpsc::channel::(100); - info!("[STREAM_SETUP] Channel created, starting LLM stream"); let llm = self.state.llm_provider.clone(); let model_clone = model.clone(); @@ -629,15 +612,13 @@ impl BotOrchestrator { let tools_for_llm = match session_tools { Ok(tools) => { if !tools.is_empty() { - info!("[TOOLS] Loaded {} tools for session {}", tools.len(), session.id); Some(tools) } else { - info!("[TOOLS] No tools associated with session {}", session.id); None } } Err(e) => { - warn!("[TOOLS] Failed to load session tools: {}", e); + warn!("Failed to load session tools: {}", e); None } }; @@ -645,24 +626,13 @@ impl BotOrchestrator { // Clone messages for the async task let messages_clone = messages.clone(); - // DEBUG: Log exact values being passed to LLM - info!("[LLM_CALL] Calling generate_stream with:"); - info!("[LLM_CALL] Model: '{}'", model_clone); - info!("[LLM_CALL] Key length: {} chars", key_clone.len()); - info!("[LLM_CALL] Key preview: '{}...{}'", - &key_clone.chars().take(8).collect::(), - &key_clone.chars().rev().take(8).collect::() - ); - tokio::spawn(async move { - info!("[SPAWN_TASK] LLM stream task started"); if let Err(e) = llm .generate_stream("", &messages_clone, stream_tx, &model_clone, &key_clone, tools_for_llm.as_ref()) .await { error!("LLM streaming error: {}", e); } - info!("[SPAWN_TASK] LLM stream task completed"); }); let mut full_response = String::new(); @@ -673,9 +643,6 @@ impl BotOrchestrator { let mut tool_was_executed = false; // Track if a tool was executed to avoid duplicate final message let handler = llm_models::get_handler(&model); - info!("[STREAM_START] Entering stream processing loop for model: {}", model); - info!("[STREAM_START] About to enter while loop, stream_rx is valid"); - trace!("Using model handler for {}", model); #[cfg(feature = "nvidia")] @@ -700,7 +667,6 @@ impl BotOrchestrator { } while let Some(chunk) = stream_rx.recv().await { - info!("[STREAM_DEBUG] Received chunk: '{}', len: {}", chunk, chunk.len()); trace!("Received LLM chunk: {:?}", chunk); // ===== GENERIC TOOL EXECUTION ===== @@ -724,7 +690,6 @@ impl BotOrchestrator { // Send the part before { as regular content let regular_part = &chunk[..pos]; if !regular_part.trim().is_empty() { - info!("[STREAM_CONTENT] Sending regular part before JSON: '{}', len: {}", regular_part, regular_part.len()); full_response.push_str(regular_part); let response = BotResponse { @@ -774,11 +739,6 @@ impl BotOrchestrator { }; if let Some(tc) = tool_call { - info!( - "[TOOL_CALL] Detected tool '{}' from LLM, executing...", - tc.tool_name - ); - let execution_result = ToolExecutor::execute_tool_call( &self.state, &bot_name_for_context, @@ -862,7 +822,6 @@ impl BotOrchestrator { // Increased limit to 50000 to handle large tool calls with many parameters if tool_call_buffer.len() > 50000 { // Flush accumulated content to client since it's too large to be a tool call - info!("[TOOL_EXEC] Flushing tool_call_buffer (too large, assuming not a tool call)"); full_response.push_str(&tool_call_buffer); let response = BotResponse { @@ -934,13 +893,9 @@ impl BotOrchestrator { if in_analysis && handler.is_analysis_complete(&analysis_buffer) { in_analysis = false; - info!( - "[ANALYSIS] Detected end of thinking for model {}. Buffer: '{}'", - model, analysis_buffer - ); + trace!("Detected end of thinking for model {}", model); let processed = handler.process_content(&analysis_buffer); - info!("[ANALYSIS] Processed content: '{}'", processed); if !processed.is_empty() { full_response.push_str(&processed); @@ -975,7 +930,6 @@ impl BotOrchestrator { } if !in_analysis { - info!("[STREAM_CONTENT] Sending chunk: '{}', len: {}", chunk, chunk.len()); full_response.push_str(&chunk); let response = BotResponse { @@ -1000,8 +954,6 @@ impl BotOrchestrator { } } - info!("[STREAM_END] While loop exited. full_response length: {}", full_response.len()); - let state_for_save = self.state.clone(); let full_response_clone = full_response.clone(); tokio::task::spawn_blocking( @@ -1366,18 +1318,14 @@ async fn handle_websocket( while let Some(Ok(msg)) = receiver.next().await { match msg { Message::Text(text) => { - info!("Received WebSocket message: {}", text); if let Ok(user_msg) = serde_json::from_str::(&text) { let orchestrator = BotOrchestrator::new(state_clone.clone()); - info!("[WS_DEBUG] Looking up response channel for session: {}", session_id); if let Some(tx_clone) = state_clone .response_channels .lock() .await .get(&session_id.to_string()) { - info!("[WS_DEBUG] Response channel found, calling stream_response"); - // Ensure session exists - create if not let session_result = { let mut sm = state_clone.session_manager.lock().await; @@ -1385,27 +1333,20 @@ async fn handle_websocket( }; let session = match session_result { - Ok(Some(sess)) => { - info!("[WS_DEBUG] Session exists: {}", session_id); - sess - } + Ok(Some(sess)) => sess, Ok(None) => { - info!("[WS_DEBUG] Session not found, creating via session manager"); // Use session manager to create session (will generate new UUID) let mut sm = state_clone.session_manager.lock().await; match sm.create_session(user_id, bot_id, "WebSocket Chat") { - Ok(new_session) => { - info!("[WS_DEBUG] Session created: {} (note: different from WebSocket session_id)", new_session.id); - new_session - } + Ok(new_session) => new_session, Err(e) => { - error!("[WS_DEBUG] Failed to create session: {}", e); + error!("Failed to create session: {}", e); continue; } } } Err(e) => { - error!("[WS_DEBUG] Error getting session: {}", e); + error!("Error getting session: {}", e); continue; } }; @@ -1424,14 +1365,14 @@ async fn handle_websocket( error!("Failed to stream response: {}", e); } } else { - warn!("[WS_DEBUG] Response channel NOT found for session: {}", session_id); + warn!("Response channel NOT found for session: {}", session_id); } } else { - warn!("[WS_DEBUG] Failed to parse UserMessage from: {}", text); + warn!("Failed to parse UserMessage from: {}", text); } } Message::Close(_) => { - info!("WebSocket close message received"); + trace!("WebSocket close message received"); break; } _ => {} diff --git a/src/core/bot/tool_executor.rs b/src/core/bot/tool_executor.rs index 8634229aa..29233d04c 100644 --- a/src/core/bot/tool_executor.rs +++ b/src/core/bot/tool_executor.rs @@ -1,6 +1,6 @@ /// Generic tool executor for LLM tool calls /// Works across all LLM providers (GLM, OpenAI, Claude, etc.) -use log::{error, info, warn}; +use log::{error, info, trace, warn}; use serde_json::Value; // use std::collections::HashMap; use std::fs::OpenOptions; @@ -60,7 +60,7 @@ impl ToolExecutor { } // Also log to system logger - error!("[TOOL_ERROR] Bot: {}, Tool: {}, Error: {}", bot_name, tool_name, error_msg); + error!("Tool error in {} (bot: {}): {}", tool_name, bot_name, error_msg); } /// Convert internal errors to user-friendly messages for browser @@ -278,7 +278,7 @@ impl ToolExecutor { // Set variable in script scope if let Err(e) = script_service.set_variable(key, &value_str) { - warn!("[TOOL_EXEC] Failed to set variable '{}': {}", key, e); + warn!("Failed to set variable '{}': {}", key, e); } } } @@ -302,7 +302,7 @@ impl ToolExecutor { // Run the script match script_service.run(&ast) { Ok(result) => { - info!("[TOOL_EXEC] Tool '{}' executed successfully", tool_name); + trace!("Tool '{}' executed successfully", tool_name); // Convert result to string let result_str = result.to_string(); diff --git a/src/core/kb/embedding_generator.rs b/src/core/kb/embedding_generator.rs index dcb59725d..f7cd6d694 100644 --- a/src/core/kb/embedding_generator.rs +++ b/src/core/kb/embedding_generator.rs @@ -20,7 +20,7 @@ pub fn is_embedding_server_ready() -> bool { pub fn set_embedding_server_ready(ready: bool) { EMBEDDING_SERVER_READY.store(ready, Ordering::SeqCst); if ready { - info!("[EMBEDDING] Embedding server marked as ready"); + info!("Embedding server marked as ready"); } } @@ -285,13 +285,13 @@ impl KbEmbeddingGenerator { is_healthy } _ => { - warn!("[EMBEDDING] Health check failed: {}", e); + warn!("Health check failed: {}", e); false } } } Err(_) => { - warn!("[EMBEDDING] Health check timed out"); + warn!("Health check timed out"); false } } @@ -301,18 +301,18 @@ impl KbEmbeddingGenerator { let start = std::time::Instant::now(); let max_wait = Duration::from_secs(max_wait_secs); - info!("[EMBEDDING] Waiting for embedding server at {} (max {}s)...", + info!("Waiting for embedding server at {} (max {}s)...", self.config.embedding_url, max_wait_secs); while start.elapsed() < max_wait { if self.check_health().await { - info!("[EMBEDDING] Embedding server is ready after {:?}", start.elapsed()); + info!("Embedding server is ready after {:?}", start.elapsed()); return true; } tokio::time::sleep(Duration::from_secs(2)).await; } - warn!("[EMBEDDING] Embedding server not available after {}s", max_wait_secs); + warn!("Embedding server not available after {}s", max_wait_secs); false } @@ -325,7 +325,7 @@ impl KbEmbeddingGenerator { } if !is_embedding_server_ready() { - info!("[EMBEDDING] Server not marked ready, checking health..."); + trace!("Server not marked ready, checking health..."); if !self.wait_for_server(30).await { return Err(anyhow::anyhow!( "Embedding server not available at {}. Skipping embedding generation.", @@ -335,7 +335,7 @@ impl KbEmbeddingGenerator { } let start_mem = MemoryStats::current(); - trace!("[EMBEDDING] Generating embeddings for {} chunks, RSS={}", + trace!("Generating embeddings for {} chunks, RSS={}", chunks.len(), MemoryStats::format_bytes(start_mem.rss_bytes)); let mut results = Vec::with_capacity(chunks.len()); @@ -343,7 +343,7 @@ impl KbEmbeddingGenerator { for (batch_num, batch) in chunks.chunks(self.config.batch_size).enumerate() { let batch_start = MemoryStats::current(); - trace!("[EMBEDDING] Processing batch {}/{} ({} items), RSS={}", + trace!("Processing batch {}/{} ({} items), RSS={}", batch_num + 1, total_batches, batch.len(), @@ -355,11 +355,11 @@ impl KbEmbeddingGenerator { ).await { Ok(Ok(embeddings)) => embeddings, Ok(Err(e)) => { - warn!("[EMBEDDING] Batch {} failed: {}", batch_num + 1, e); + warn!("Batch {} failed: {}", batch_num + 1, e); break; } Err(_) => { - warn!("[EMBEDDING] Batch {} timed out after {}s", + warn!("Batch {} timed out after {}s", batch_num + 1, self.config.timeout_seconds); break; } @@ -367,14 +367,14 @@ impl KbEmbeddingGenerator { let batch_end = MemoryStats::current(); let delta = batch_end.rss_bytes.saturating_sub(batch_start.rss_bytes); - trace!("[EMBEDDING] Batch {} complete: {} embeddings, RSS={} (delta={})", + trace!("Batch {} complete: {} embeddings, RSS={} (delta={})", batch_num + 1, batch_embeddings.len(), MemoryStats::format_bytes(batch_end.rss_bytes), MemoryStats::format_bytes(delta)); if delta > 100 * 1024 * 1024 { - warn!("[EMBEDDING] Excessive memory growth detected ({}), stopping early", + warn!("Excessive memory growth detected ({}), stopping early", MemoryStats::format_bytes(delta)); for (chunk, embedding) in batch.iter().zip(batch_embeddings.iter()) { results.push((chunk.clone(), embedding.clone())); @@ -392,7 +392,7 @@ impl KbEmbeddingGenerator { } let end_mem = MemoryStats::current(); - trace!("[EMBEDDING] Generated {} embeddings, RSS={} (total delta={})", + trace!("Generated {} embeddings, RSS={} (total delta={})", results.len(), MemoryStats::format_bytes(end_mem.rss_bytes), MemoryStats::format_bytes(end_mem.rss_bytes.saturating_sub(start_mem.rss_bytes))); @@ -408,16 +408,16 @@ impl KbEmbeddingGenerator { let texts: Vec = chunks.iter().map(|c| c.content.clone()).collect(); let total_chars: usize = texts.iter().map(|t| t.len()).sum(); - info!("[EMBEDDING] generate_batch_embeddings: {} texts, {} total chars", + trace!("generate_batch_embeddings: {} texts, {} total chars", texts.len(), total_chars); match self.generate_local_embeddings(&texts).await { Ok(embeddings) => { - info!("[EMBEDDING] Local embeddings succeeded: {} vectors", embeddings.len()); + trace!("Local embeddings succeeded: {} vectors", embeddings.len()); Ok(embeddings) } Err(e) => { - warn!("[EMBEDDING] Local embedding service failed: {}", e); + warn!("Local embedding service failed: {}", e); Err(e) } } @@ -437,7 +437,7 @@ impl KbEmbeddingGenerator { let request_size = serde_json::to_string(&request) .map(|s| s.len()) .unwrap_or(0); - info!("[EMBEDDING] Sending request to {} (size: {} bytes)", + trace!("Sending request to {} (size: {} bytes)", self.config.embedding_url, request_size); let response = self @@ -462,7 +462,7 @@ impl KbEmbeddingGenerator { let response_bytes = response.bytes().await .context("Failed to read embedding response bytes")?; - info!("[EMBEDDING] Received response: {} bytes", response_bytes.len()); + trace!("Received response: {} bytes", response_bytes.len()); if response_bytes.len() > 50 * 1024 * 1024 { return Err(anyhow::anyhow!( diff --git a/src/core/kb/kb_indexer.rs b/src/core/kb/kb_indexer.rs index 8a7d1d9b8..b4a7b576d 100644 --- a/src/core/kb/kb_indexer.rs +++ b/src/core/kb/kb_indexer.rs @@ -126,7 +126,7 @@ impl KbIndexer { log_jemalloc_stats(); if !is_embedding_server_ready() { - info!("[KB_INDEXER] Embedding server not ready yet, waiting up to 60s..."); + info!("Embedding server not ready yet, waiting up to 60s..."); if !self.embedding_generator.wait_for_server(60).await { warn!( "Embedding server is not available. KB indexing skipped. \ @@ -155,13 +155,13 @@ impl KbIndexer { self.ensure_collection_exists(&collection_name).await?; let before_docs = MemoryStats::current(); - trace!("[KB_INDEXER] Before process_kb_folder RSS={}", + trace!("Before process_kb_folder RSS={}", MemoryStats::format_bytes(before_docs.rss_bytes)); let documents = self.document_processor.process_kb_folder(kb_path).await?; let after_docs = MemoryStats::current(); - trace!("[KB_INDEXER] After process_kb_folder: {} documents, RSS={} (delta={})", + trace!("After process_kb_folder: {} documents, RSS={} (delta={})", documents.len(), MemoryStats::format_bytes(after_docs.rss_bytes), MemoryStats::format_bytes(after_docs.rss_bytes.saturating_sub(before_docs.rss_bytes))); @@ -176,7 +176,7 @@ impl KbIndexer { for (doc_path, chunks) in doc_iter { if chunks.is_empty() { - debug!("[KB_INDEXER] Skipping document with no chunks: {}", doc_path); + debug!("Skipping document with no chunks: {}", doc_path); continue; } @@ -198,7 +198,7 @@ impl KbIndexer { // Memory pressure check - more aggressive let current_mem = MemoryStats::current(); if current_mem.rss_bytes > 1_500_000_000 { // 1.5GB threshold (reduced) - warn!("[KB_INDEXER] High memory usage detected: {}, forcing cleanup", + warn!("High memory usage detected: {}, forcing cleanup", MemoryStats::format_bytes(current_mem.rss_bytes)); // Force garbage collection hint @@ -220,7 +220,7 @@ impl KbIndexer { self.update_collection_metadata(&collection_name, bot_name, kb_name, total_chunks)?; let end_mem = MemoryStats::current(); - trace!("[KB_INDEXER] Indexing complete: {} docs, {} chunks, RSS={} (total delta={})", + trace!("Indexing complete: {} docs, {} chunks, RSS={} (total delta={})", indexed_documents, total_chunks, MemoryStats::format_bytes(end_mem.rss_bytes), MemoryStats::format_bytes(end_mem.rss_bytes.saturating_sub(start_mem.rss_bytes))); @@ -245,7 +245,7 @@ impl KbIndexer { while let Some((doc_path, chunks)) = batch_docs.pop() { let before_embed = MemoryStats::current(); trace!( - "[KB_INDEXER] Processing document: {} ({} chunks) RSS={}", + "Processing document: {} ({} chunks) RSS={}", doc_path, chunks.len(), MemoryStats::format_bytes(before_embed.rss_bytes) @@ -253,7 +253,7 @@ impl KbIndexer { // Re-validate embedding server is still available if !is_embedding_server_ready() { - warn!("[KB_INDEXER] Embedding server became unavailable during indexing, aborting batch"); + warn!("Embedding server became unavailable during indexing, aborting batch"); return Err(anyhow::anyhow!( "Embedding server became unavailable during KB indexing. Processed {} documents before failure.", processed_count @@ -265,7 +265,7 @@ impl KbIndexer { let chunk_batches = chunks.chunks(CHUNK_BATCH_SIZE); for chunk_batch in chunk_batches { - trace!("[KB_INDEXER] Processing chunk batch of {} chunks", chunk_batch.len()); + trace!("Processing chunk batch of {} chunks", chunk_batch.len()); let embeddings = match self .embedding_generator @@ -274,7 +274,7 @@ impl KbIndexer { { Ok(emb) => emb, Err(e) => { - warn!("[KB_INDEXER] Embedding generation failed for {}: {}", doc_path, e); + warn!("Embedding generation failed for {}: {}", doc_path, e); break; // Skip to next document } }; @@ -287,7 +287,7 @@ impl KbIndexer { } let after_embed = MemoryStats::current(); - trace!("[KB_INDEXER] After processing document: RSS={} (delta={})", + trace!("After processing document: RSS={} (delta={})", MemoryStats::format_bytes(after_embed.rss_bytes), MemoryStats::format_bytes(after_embed.rss_bytes.saturating_sub(before_embed.rss_bytes))); diff --git a/src/core/kb/website_crawler_service.rs b/src/core/kb/website_crawler_service.rs index f09afbde8..22cf01f34 100644 --- a/src/core/kb/website_crawler_service.rs +++ b/src/core/kb/website_crawler_service.rs @@ -4,7 +4,7 @@ use crate::core::kb::KnowledgeBaseManager; use crate::core::shared::state::AppState; use crate::core::shared::utils::DbPool; use diesel::prelude::*; -use log::{error, info, warn}; +use log::{error, trace, warn}; use regex; use std::collections::HashSet; use std::sync::Arc; @@ -35,7 +35,7 @@ impl WebsiteCrawlerService { let service = Arc::clone(&self); tokio::spawn(async move { - info!("Website crawler service started"); + trace!("Website crawler service started"); let mut ticker = interval(service.check_interval); @@ -59,7 +59,7 @@ impl WebsiteCrawlerService { } async fn check_and_crawl_websites(&self) -> Result<(), Box> { - info!("Checking for websites that need recrawling"); + trace!("Checking for websites that need recrawling"); // First, scan for new USE WEBSITE commands in .bas files self.scan_and_register_websites_from_scripts()?; @@ -75,9 +75,9 @@ impl WebsiteCrawlerService { ) .load(&mut conn)?; - info!("Total websites in database: {}", all_websites.len()); + trace!("Total websites in database: {}", all_websites.len()); for ws in &all_websites { - info!(" - URL: {}, status: {:?}, refresh: {:?}", ws.url, ws.crawl_status, ws.refresh_policy); + trace!(" - URL: {}, status: {:?}, refresh: {:?}", ws.url, ws.crawl_status, ws.refresh_policy); } let websites = diesel::sql_query( @@ -90,7 +90,7 @@ impl WebsiteCrawlerService { ) .load::(&mut conn)?; - info!("Found {} websites to recrawl (next_crawl <= NOW())", websites.len()); + trace!("Found {} websites to recrawl (next_crawl <= NOW())", websites.len()); // Process websites sequentially to prevent memory exhaustion for website in websites { @@ -115,11 +115,11 @@ impl WebsiteCrawlerService { let db_pool = self.db_pool.clone(); let active_crawls = Arc::clone(&self.active_crawls); - info!("Processing website: {}", website.url); + trace!("Processing website: {}", website.url); match Self::crawl_website(website, kb_manager, db_pool, active_crawls).await { Ok(_) => { - info!("Successfully processed website crawl"); + trace!("Successfully processed website crawl"); } Err(e) => { error!("Failed to crawl website: {}", e); @@ -165,7 +165,7 @@ impl WebsiteCrawlerService { }); }; - info!("Starting crawl for website: {}", website.url); + trace!("Starting crawl for website: {}", website.url); let config_manager = ConfigManager::new(db_pool.clone()); @@ -200,7 +200,7 @@ impl WebsiteCrawlerService { match crawler.crawl().await { Ok(pages) => { - info!("Crawled {} pages from {}", pages.len(), website.url); + trace!("Crawled {} pages from {}", pages.len(), website.url); let mut conn = db_pool.get()?; #[derive(QueryableByName)] @@ -228,7 +228,7 @@ impl WebsiteCrawlerService { let total_pages = pages.len(); for (batch_idx, batch) in pages.chunks(BATCH_SIZE).enumerate() { - info!("Processing batch {} of {} pages", batch_idx + 1, total_pages.div_ceil(BATCH_SIZE)); + trace!("Processing batch {} of {} pages", batch_idx + 1, total_pages.div_ceil(BATCH_SIZE)); for (idx, page) in batch.iter().enumerate() { let global_idx = batch_idx * BATCH_SIZE + idx; @@ -258,7 +258,7 @@ impl WebsiteCrawlerService { if batch_idx == 0 || (batch_idx + 1) % 2 == 0 { // Index every 2 batches to prevent memory buildup match kb_manager.index_kb_folder(&bot_name, &kb_name, &work_path).await { - Ok(_) => info!("Indexed batch {} successfully", batch_idx + 1), + Ok(_) => trace!("Indexed batch {} successfully", batch_idx + 1), Err(e) => warn!("Failed to index batch {}: {}", batch_idx + 1, e), } @@ -290,7 +290,7 @@ impl WebsiteCrawlerService { .bind::(&website.id) .execute(&mut conn)?; - info!( + trace!( "Successfully recrawled {}, next crawl: {:?}", website.url, config.next_crawl ); @@ -318,7 +318,7 @@ impl WebsiteCrawlerService { } fn scan_and_register_websites_from_scripts(&self) -> Result<(), Box> { - info!("Scanning .bas files for USE WEBSITE commands"); + trace!("Scanning .bas files for USE WEBSITE commands"); let work_dir = std::path::Path::new("work"); if !work_dir.exists() { @@ -416,7 +416,7 @@ impl WebsiteCrawlerService { .unwrap_or(0); if exists == 0 { - info!("Auto-registering website {} for bot {} with refresh: {}", url_str, bot_id, refresh_str); + trace!("Auto-registering website {} for bot {} with refresh: {}", url_str, bot_id, refresh_str); // Register website for crawling with refresh policy crate::basic::keywords::use_website::register_website_for_crawling_with_refresh( @@ -480,7 +480,7 @@ pub async fn ensure_crawler_service_running( drop(service.start()); - info!("Website crawler service initialized"); + trace!("Website crawler service initialized"); Ok(()) } else { diff --git a/src/core/package_manager/installer.rs b/src/core/package_manager/installer.rs index 730448466..521f64939 100644 --- a/src/core/package_manager/installer.rs +++ b/src/core/package_manager/installer.rs @@ -1080,7 +1080,7 @@ EOF"#.to_string(), component.name, rendered_cmd ); - trace!("[START] Working dir: {}", bin_path.display()); + trace!("Working dir: {}", bin_path.display()); let child = SafeCommand::new("sh") .and_then(|c| c.arg("-c")) .and_then(|c| c.trusted_shell_script_arg(&rendered_cmd)) diff --git a/src/core/shared/memory_monitor.rs b/src/core/shared/memory_monitor.rs index 1076b2fce..8087a17da 100644 --- a/src/core/shared/memory_monitor.rs +++ b/src/core/shared/memory_monitor.rs @@ -31,7 +31,7 @@ component: component.to_string(), if let Ok(mut registry) = THREAD_REGISTRY.write() { registry.insert(name.to_string(), info); } -trace!("[THREAD] Registered: {} (component: {})", name, component); +trace!("Registered: {} (component: {})", name, component); } pub fn record_thread_activity(name: &str) { @@ -47,12 +47,12 @@ pub fn unregister_thread(name: &str) { if let Ok(mut registry) = THREAD_REGISTRY.write() { registry.remove(name); } -info!("[THREAD] Unregistered: {}", name); +info!("Unregistered: {}", name); } pub fn log_thread_stats() { if let Ok(registry) = THREAD_REGISTRY.read() { -info!("[THREADS] Active thread count: {}", registry.len()); +info!("Active thread count: {}", registry.len()); for (name, info) in registry.iter() { let uptime = info.started_at.elapsed().as_secs(); let idle = info.last_activity.elapsed().as_secs(); @@ -185,7 +185,7 @@ if let Some(stats) = get_jemalloc_stats() { stats.log(); let frag = stats.fragmentation_ratio(); if frag > 1.5 { -warn!("[JEMALLOC] High fragmentation detected: {:.2}x", frag); +warn!("High fragmentation detected: {:.2}x", frag); } } } @@ -446,7 +446,7 @@ tokio::spawn(async move { record_component("global"); if let Some(warning) = detector.check() { - warn!("[MONITOR] {}", warning); + warn!("{}", warning); stats.log(); log_component_stats(); log_thread_stats(); @@ -454,7 +454,7 @@ tokio::spawn(async move { // Switch to normal interval after startup period if tick_count == startup_ticks { - trace!("[MONITOR] Switching to normal interval ({}s)", interval_secs); + trace!("Switching to normal interval ({}s)", interval_secs); interval = tokio::time::interval(normal_interval); } } diff --git a/src/core/shared/state.rs b/src/core/shared/state.rs index a19d9bb61..c62666527 100644 --- a/src/core/shared/state.rs +++ b/src/core/shared/state.rs @@ -505,7 +505,7 @@ impl std::fmt::Debug for AppState { impl AppState { pub fn broadcast_task_progress(&self, event: TaskProgressEvent) { log::info!( - "[TASK_PROGRESS] Broadcasting: task_id={}, step={}, message={}", + "Broadcasting: task_id={}, step={}, message={}", event.task_id, event.step, event.message @@ -513,19 +513,19 @@ impl AppState { if let Some(tx) = &self.task_progress_broadcast { let receiver_count = tx.receiver_count(); log::info!( - "[TASK_PROGRESS] Broadcast channel has {} receivers", + "Broadcast channel has {} receivers", receiver_count ); match tx.send(event) { Ok(_) => { - log::info!("[TASK_PROGRESS] Event sent successfully"); + log::info!("Event sent successfully"); } Err(e) => { - log::warn!("[TASK_PROGRESS] No listeners for task progress: {e}"); + log::warn!("No listeners for task progress: {e}"); } } } else { - log::warn!("[TASK_PROGRESS] No broadcast channel configured!"); + log::warn!("No broadcast channel configured!"); } } diff --git a/src/drive/drive_monitor/mod.rs b/src/drive/drive_monitor/mod.rs index 00f4a0807..a588841e2 100644 --- a/src/drive/drive_monitor/mod.rs +++ b/src/drive/drive_monitor/mod.rs @@ -211,7 +211,7 @@ impl DriveMonitor { // Check if already processing to prevent duplicate monitoring if self.is_processing.load(std::sync::atomic::Ordering::Acquire) { - warn!("[DRIVE_MONITOR] Already processing for bot {}, skipping", self.bot_id); + warn!("Already processing for bot {}, skipping", self.bot_id); return Ok(()); } @@ -234,18 +234,18 @@ impl DriveMonitor { .store(true, std::sync::atomic::Ordering::SeqCst); trace!("start_monitoring: calling check_for_changes..."); - info!("[DRIVE_MONITOR] Calling initial check_for_changes..."); + info!("Calling initial check_for_changes..."); match tokio::time::timeout(Duration::from_secs(300), self.check_for_changes()).await { Ok(Ok(_)) => { self.consecutive_failures.store(0, Ordering::Relaxed); } Ok(Err(e)) => { - warn!("[DRIVE_MONITOR] Initial check failed (will retry): {}", e); + warn!("Initial check failed (will retry): {}", e); self.consecutive_failures.fetch_add(1, Ordering::Relaxed); } Err(_) => { - error!("[DRIVE_MONITOR] Initial check timed out after 5 minutes"); + error!("Initial check timed out after 5 minutes"); self.consecutive_failures.fetch_add(1, Ordering::Relaxed); } } @@ -260,15 +260,15 @@ impl DriveMonitor { // Force enable periodic monitoring regardless of initial check result self.is_processing.store(true, std::sync::atomic::Ordering::SeqCst); - info!("[DRIVE_MONITOR] Forced is_processing to true for periodic monitoring"); + info!("Forced is_processing to true for periodic monitoring"); let self_clone = self.clone(); // Don't wrap in Arc::new - that creates a copy tokio::spawn(async move { let mut consecutive_processing_failures = 0; - info!("[DRIVE_MONITOR] Starting periodic monitoring loop for bot {}", self_clone.bot_id); + info!("Starting periodic monitoring loop for bot {}", self_clone.bot_id); let is_processing_state = self_clone.is_processing.load(std::sync::atomic::Ordering::SeqCst); - info!("[DRIVE_MONITOR] is_processing state at loop start: {} for bot {}", is_processing_state, self_clone.bot_id); + info!("is_processing state at loop start: {} for bot {}", is_processing_state, self_clone.bot_id); while self_clone .is_processing @@ -288,7 +288,7 @@ impl DriveMonitor { .fetch_add(1, Ordering::Relaxed) + 1; if failures % 10 == 1 { - warn!("[DRIVE_MONITOR] S3/MinIO unavailable for bucket {} (failures: {}), backing off to {:?}", + warn!("S3/MinIO unavailable for bucket {} (failures: {}), backing off to {:?}", self_clone.bucket_name, failures, self_clone.calculate_backoff()); } continue; @@ -302,7 +302,7 @@ impl DriveMonitor { self_clone.consecutive_failures.swap(0, Ordering::Relaxed); consecutive_processing_failures = 0; if prev_failures > 0 { - info!("[DRIVE_MONITOR] S3/MinIO recovered for bucket {} after {} failures", + info!("S3/MinIO recovered for bucket {} after {} failures", self_clone.bucket_name, prev_failures); } } @@ -315,18 +315,18 @@ impl DriveMonitor { // If too many consecutive failures, stop processing temporarily if consecutive_processing_failures > 10 { - error!("[DRIVE_MONITOR] Too many consecutive failures ({}), stopping processing for bot {}", + error!("Too many consecutive failures ({}), stopping processing for bot {}", consecutive_processing_failures, self_clone.bot_id); self_clone.is_processing.store(false, std::sync::atomic::Ordering::SeqCst); break; } } Err(_) => { - error!("[DRIVE_MONITOR] check_for_changes timed out for bot {}", self_clone.bot_id); + error!("check_for_changes timed out for bot {}", self_clone.bot_id); consecutive_processing_failures += 1; if consecutive_processing_failures > 5 { - error!("[DRIVE_MONITOR] Too many timeouts, stopping processing for bot {}", self_clone.bot_id); + error!("Too many timeouts, stopping processing for bot {}", self_clone.bot_id); self_clone.is_processing.store(false, std::sync::atomic::Ordering::SeqCst); break; } @@ -334,7 +334,7 @@ impl DriveMonitor { } } - info!("[DRIVE_MONITOR] Monitoring loop ended for bot {}", self_clone.bot_id); + info!("Monitoring loop ended for bot {}", self_clone.bot_id); }); info!("DriveMonitor started for bot {}", self.bot_id); @@ -373,7 +373,7 @@ impl DriveMonitor { if !self.check_drive_health().await { let failures = self.consecutive_failures.fetch_add(1, Ordering::Relaxed) + 1; if failures % 10 == 1 { - warn!("[DRIVE_MONITOR] S3/MinIO unavailable for bucket {} (failures: {}), backing off to {:?}", + warn!("S3/MinIO unavailable for bucket {} (failures: {}), backing off to {:?}", self.bucket_name, failures, self.calculate_backoff()); } continue; @@ -385,7 +385,7 @@ impl DriveMonitor { Ok(_) => { let prev_failures = self.consecutive_failures.swap(0, Ordering::Relaxed); if prev_failures > 0 { - info!("[DRIVE_MONITOR] S3/MinIO recovered for bucket {} after {} failures", + info!("S3/MinIO recovered for bucket {} after {} failures", self.bucket_name, prev_failures); } } @@ -408,12 +408,12 @@ impl DriveMonitor { ); let Some(client) = &self.state.drive else { - warn!("[DRIVE_MONITOR] No drive client available for bot {}, skipping file monitoring", self.bot_id); + warn!("No drive client available for bot {}, skipping file monitoring", self.bot_id); return Ok(()); }; trace!("check_for_changes: calling check_gbdialog_changes..."); - trace!("[DRIVE_MONITOR] Checking gbdialog..."); + trace!("Checking gbdialog..."); self.check_gbdialog_changes(client).await?; trace!("check_for_changes: check_gbdialog_changes done"); let after_dialog = MemoryStats::current(); @@ -424,7 +424,7 @@ impl DriveMonitor { ); trace!("check_for_changes: calling check_gbot..."); - trace!("[DRIVE_MONITOR] Checking gbot..."); + trace!("Checking gbot..."); self.check_gbot(client).await?; trace!("check_for_changes: check_gbot done"); let after_gbot = MemoryStats::current(); @@ -435,7 +435,7 @@ impl DriveMonitor { ); trace!("check_for_changes: calling check_gbkb_changes..."); - trace!("[DRIVE_MONITOR] Checking gbkb..."); + trace!("Checking gbkb..."); self.check_gbkb_changes(client).await?; trace!("check_for_changes: check_gbkb_changes done"); let after_gbkb = MemoryStats::current(); @@ -531,7 +531,7 @@ impl DriveMonitor { let self_clone = Arc::new(self.clone()); tokio::spawn(async move { if let Err(e) = self_clone.save_file_states().await { - warn!("[DRIVE_MONITOR] Failed to save file states: {}", e); + warn!("Failed to save file states: {}", e); } }); Ok(()) @@ -1145,7 +1145,7 @@ impl DriveMonitor { #[cfg(any(feature = "research", feature = "llm"))] { if !is_embedding_server_ready() { - info!("[DRIVE_MONITOR] Embedding server not ready, deferring KB indexing for {}", kb_folder_path.display()); + info!("Embedding server not ready, deferring KB indexing for {}", kb_folder_path.display()); continue; } @@ -1256,7 +1256,7 @@ impl DriveMonitor { let self_clone = Arc::new(self.clone()); tokio::spawn(async move { if let Err(e) = self_clone.save_file_states().await { - warn!("[DRIVE_MONITOR] Failed to save file states: {}", e); + warn!("Failed to save file states: {}", e); } }); diff --git a/src/drive/local_file_monitor.rs b/src/drive/local_file_monitor.rs index 9231e01a8..ebae32bb4 100644 --- a/src/drive/local_file_monitor.rs +++ b/src/drive/local_file_monitor.rs @@ -36,7 +36,7 @@ impl LocalFileMonitor { // Use botserver/work as the work directory for generated files let work_root = PathBuf::from("work"); - info!("[LOCAL_MONITOR] Initializing with data_dir: {:?}, work_root: {:?}", data_dir, work_root); + info!("Initializing with data_dir: {:?}, work_root: {:?}", data_dir, work_root); Self { state, @@ -48,11 +48,11 @@ impl LocalFileMonitor { } pub async fn start_monitoring(&self) -> Result<(), Box> { - info!("[LOCAL_MONITOR] Starting local file monitor for /opt/gbo/data/*.gbai directories"); + info!("Starting local file monitor for /opt/gbo/data/*.gbai directories"); // Create data directory if it doesn't exist if let Err(e) = tokio::fs::create_dir_all(&self.data_dir).await { - warn!("[LOCAL_MONITOR] Failed to create data directory: {}", e); + warn!("Failed to create data directory: {}", e); } // Initial scan of all .gbai directories @@ -66,12 +66,12 @@ impl LocalFileMonitor { monitor.monitoring_loop().await; }); - info!("[LOCAL_MONITOR] Local file monitor started"); + info!("Local file monitor started"); Ok(()) } async fn monitoring_loop(&self) { - info!("[LOCAL_MONITOR] Starting monitoring loop"); + info!("Starting monitoring loop"); // Try to create a file system watcher let (tx, mut rx) = tokio::sync::mpsc::channel(100); @@ -88,7 +88,7 @@ impl LocalFileMonitor { ) { Ok(w) => w, Err(e) => { - error!("[LOCAL_MONITOR] Failed to create watcher: {}. Falling back to polling.", e); + error!("Failed to create watcher: {}. Falling back to polling.", e); // Fall back to polling if watcher creation fails self.polling_loop().await; return; @@ -97,13 +97,13 @@ impl LocalFileMonitor { // Watch the data directory if let Err(e) = watcher.watch(&self.data_dir, RecursiveMode::Recursive) { - warn!("[LOCAL_MONITOR] Failed to watch directory {:?}: {}. Using polling fallback.", self.data_dir, e); + warn!("Failed to watch directory {:?}: {}. Using polling fallback.", self.data_dir, e); drop(watcher); self.polling_loop().await; return; } - info!("[LOCAL_MONITOR] Watching directory: {:?}", self.data_dir); + info!("Watching directory: {:?}", self.data_dir); while self.is_processing.load(Ordering::SeqCst) { tokio::time::sleep(Duration::from_secs(5)).await; @@ -114,9 +114,9 @@ impl LocalFileMonitor { EventKind::Create(_) | EventKind::Modify(_) | EventKind::Any => { for path in &event.paths { if self.is_gbdialog_file(path) { - info!("[LOCAL_MONITOR] Detected change: {:?}", path); + info!("Detected change: {:?}", path); if let Err(e) = self.compile_local_file(path).await { - error!("[LOCAL_MONITOR] Failed to compile {:?}: {}", path, e); + error!("Failed to compile {:?}: {}", path, e); } } } @@ -124,7 +124,7 @@ impl LocalFileMonitor { EventKind::Remove(_) => { for path in &event.paths { if self.is_gbdialog_file(path) { - info!("[LOCAL_MONITOR] File removed: {:?}", path); + info!("File removed: {:?}", path); self.remove_file_state(path).await; } } @@ -135,21 +135,21 @@ impl LocalFileMonitor { // Periodic scan to catch any missed changes if let Err(e) = self.scan_and_compile_all().await { - error!("[LOCAL_MONITOR] Scan failed: {}", e); + error!("Scan failed: {}", e); } } - info!("[LOCAL_MONITOR] Monitoring loop ended"); + info!("Monitoring loop ended"); } async fn polling_loop(&self) { - info!("[LOCAL_MONITOR] Using polling fallback (checking every 10s)"); + info!("Using polling fallback (checking every 10s)"); while self.is_processing.load(Ordering::SeqCst) { tokio::time::sleep(Duration::from_secs(10)).await; if let Err(e) = self.scan_and_compile_all().await { - error!("[LOCAL_MONITOR] Scan failed: {}", e); + error!("Scan failed: {}", e); } } } @@ -229,9 +229,9 @@ impl LocalFileMonitor { }; if should_compile { - info!("[LOCAL_MONITOR] Compiling: {:?}", path); + info!("Compiling: {:?}", path); if let Err(e) = self.compile_local_file(&path).await { - error!("[LOCAL_MONITOR] Failed to compile {:?}: {}", path, e); + error!("Failed to compile {:?}: {}", path, e); } // Update state @@ -304,7 +304,7 @@ impl LocalFileMonitor { }) .await??; - info!("[LOCAL_MONITOR] Successfully compiled: {:?}", file_path); + info!("Successfully compiled: {:?}", file_path); Ok(()) } @@ -315,7 +315,7 @@ impl LocalFileMonitor { } pub async fn stop_monitoring(&self) { - info!("[LOCAL_MONITOR] Stopping local file monitor"); + info!("Stopping local file monitor"); self.is_processing.store(false, Ordering::SeqCst); self.file_states.write().await.clear(); } diff --git a/src/llm/claude.rs b/src/llm/claude.rs index 450bf8633..fcd0da509 100644 --- a/src/llm/claude.rs +++ b/src/llm/claude.rs @@ -421,7 +421,7 @@ impl ClaudeClient { if !status.is_success() { let error_text = response.text().await.unwrap_or_default(); - error!("[CLAUDE] Error response: {}", error_text); + error!("Claude API error response: {}", error_text); return Err(format!("HTTP {}: {}", status, error_text).into()); } diff --git a/src/llm/glm.rs b/src/llm/glm.rs index e5eda1a0b..9166e8f18 100644 --- a/src/llm/glm.rs +++ b/src/llm/glm.rs @@ -304,7 +304,7 @@ impl LLMProvider for GLMClient { match tx.send(tool_call_json).await { Ok(_) => {}, Err(e) => { - error!("[GLM_TX] Failed to send tool_call to channel: {}", e); + error!("Failed to send tool_call to channel: {}", e); } } } @@ -318,7 +318,7 @@ impl LLMProvider for GLMClient { match tx.send(content.to_string()).await { Ok(_) => {}, Err(e) => { - error!("[GLM_TX] Failed to send to channel: {}", e); + error!("Failed to send to channel: {}", e); } } } diff --git a/src/llm/mod.rs b/src/llm/mod.rs index 08d1136ca..dbe70a4f6 100644 --- a/src/llm/mod.rs +++ b/src/llm/mod.rs @@ -407,6 +407,19 @@ impl LLMProvider for OpenAIClient { let _ = tx.send(processed).await; } } + + // Handle standard OpenAI tool_calls + if let Some(tool_calls) = data["choices"][0]["delta"]["tool_calls"].as_array() { + for tool_call in tool_calls { + // We send the tool_call object as a JSON string so stream_response + // can buffer it and parse it using ToolExecutor::parse_tool_call + if let Some(func) = tool_call.get("function") { + if let Some(args) = func.get("arguments").and_then(|a| a.as_str()) { + let _ = tx.send(args.to_string()).await; + } + } + } + } } } } diff --git a/src/tasks/task_api/handlers.rs b/src/tasks/task_api/handlers.rs index bc4f96cc0..e59bac005 100644 --- a/src/tasks/task_api/handlers.rs +++ b/src/tasks/task_api/handlers.rs @@ -69,7 +69,7 @@ pub async fn handle_task_list( let result = tokio::task::spawn_blocking(move || { let mut db_conn = conn.get().map_err(|e| { - error!("[TASK_LIST] DB connection error: {}", e); + error!("DB connection error: {}", e); diesel::result::Error::DatabaseError( diesel::result::DatabaseErrorKind::UnableToSendCommand, Box::new(e.to_string()), @@ -95,7 +95,7 @@ pub async fn handle_task_list( ) .load::(&mut db_conn) .map_err(|e| { - error!("[TASK_LIST] Query error: {}", e); + error!("Query error: {}", e); e })?; @@ -106,11 +106,11 @@ pub async fn handle_task_list( match result { Ok(Ok(tasks)) => (StatusCode::OK, axum::Json(tasks)).into_response(), Ok(Err(e)) => { - error!("[TASK_LIST] DB error: {}", e); + error!("DB error: {}", e); (StatusCode::INTERNAL_SERVER_ERROR, "Database error").into_response() } Err(e) => { - error!("[TASK_LIST] Task join error: {}", e); + error!("Task join error: {}", e); (StatusCode::INTERNAL_SERVER_ERROR, "Internal server error").into_response() } } @@ -122,7 +122,7 @@ pub async fn handle_task_get( Path(id): Path, headers: axum::http::HeaderMap, ) -> impl IntoResponse { - info!("[TASK_GET] *** Handler called for task: {} ***", id); + info!("*** Handler called for task: {} ***", id); // Check if client wants JSON (for polling) vs HTML (for HTMX) let wants_json = headers @@ -138,7 +138,7 @@ pub async fn handle_task_get( let mut db_conn = conn .get() .map_err(|e| { - error!("[TASK_GET] DB connection error: {}", e); + error!("DB connection error: {}", e); format!("DB connection error: {}", e) })?; @@ -176,11 +176,11 @@ pub async fn handle_task_get( let parsed_uuid = match Uuid::parse_str(&task_id) { Ok(u) => { - info!("[TASK_GET] Parsed UUID: {}", u); + info!("Parsed UUID: {}", u); u } Err(e) => { - error!("[TASK_GET] Invalid task ID '{}': {}", task_id, e); + error!("Invalid task ID '{}': {}", task_id, e); return Err(format!("Invalid task ID: {}", task_id)); } }; @@ -192,12 +192,12 @@ pub async fn handle_task_get( .bind::(parsed_uuid) .get_result(&mut db_conn) .map_err(|e| { - error!("[TASK_GET] Query error for {}: {}", parsed_uuid, e); + error!("Query error for {}: {}", parsed_uuid, e); e }) .ok(); - info!("[TASK_GET] Query result for {}: found={}", parsed_uuid, task.is_some()); + info!("Query result for {}: found={}", parsed_uuid, task.is_some()); Ok::<_, String>(task) }) .await @@ -208,7 +208,7 @@ pub async fn handle_task_get( match result { Ok(Some(task)) => { - info!("[TASK_GET] Returning task: {} - {} (wants_json={})", task.id, task.title, wants_json); + info!("Returning task: {} - {} (wants_json={})", task.id, task.title, wants_json); // Return JSON for API polling clients if wants_json { @@ -371,11 +371,11 @@ pub async fn handle_task_get( (StatusCode::OK, axum::response::Html(html)).into_response() } Ok(None) => { - warn!("[TASK_GET] Task not found: {}", id); + warn!("Task not found: {}", id); (StatusCode::NOT_FOUND, axum::response::Html("
Task not found
".to_string())).into_response() } Err(e) => { - error!("[TASK_GET] Error fetching task {}: {}", id, e); + error!("Error fetching task {}: {}", id, e); (StatusCode::INTERNAL_SERVER_ERROR, axum::response::Html(format!("
{}
", e))).into_response() } } diff --git a/src/tasks/task_api/html_renderers.rs b/src/tasks/task_api/html_renderers.rs index 68d5ef4c3..70c139dbe 100644 --- a/src/tasks/task_api/html_renderers.rs +++ b/src/tasks/task_api/html_renderers.rs @@ -62,12 +62,12 @@ pub fn build_terminal_html(step_results: &Option, status: &st } pub fn build_taskmd_html(state: &Arc, task_id: &str, title: &str, runtime: &str, db_manifest: Option<&serde_json::Value>) -> (String, String) { - log::info!("[TASKMD_HTML] Building TASK.md view for task_id: {}", task_id); + log::info!("Building TASK.md view for task_id: {}", task_id); // First, try to get manifest from in-memory cache (for active/running tasks) if let Ok(manifests) = state.task_manifests.read() { if let Some(manifest) = manifests.get(task_id) { - log::info!("[TASKMD_HTML] Found manifest in memory for task: {} with {} sections", manifest.app_name, manifest.sections.len()); + log::info!("Found manifest in memory for task: {} with {} sections", manifest.app_name, manifest.sections.len()); let status_html = build_status_section_html(manifest, title, runtime); let progress_html = build_progress_log_html(manifest); return (status_html, progress_html); @@ -76,25 +76,25 @@ pub fn build_taskmd_html(state: &Arc, task_id: &str, title: &str, runt // If not in memory, try to load from database (for completed/historical tasks) if let Some(manifest_json) = db_manifest { - log::info!("[TASKMD_HTML] Found manifest in database for task: {}", task_id); + log::info!("Found manifest in database for task: {}", task_id); if let Ok(manifest) = serde_json::from_value::(manifest_json.clone()) { - log::info!("[TASKMD_HTML] Parsed DB manifest for task: {} with {} sections", manifest.app_name, manifest.sections.len()); + log::info!("Parsed DB manifest for task: {} with {} sections", manifest.app_name, manifest.sections.len()); let status_html = build_status_section_html(&manifest, title, runtime); let progress_html = build_progress_log_html(&manifest); return (status_html, progress_html); } else { // Try parsing as web JSON format (the format we store) if let Some(web_manifest) = super::utils::parse_web_manifest_json(manifest_json) { - log::info!("[TASKMD_HTML] Parsed web manifest from DB for task: {}", task_id); + log::info!("Parsed web manifest from DB for task: {}", task_id); let status_html = build_status_section_from_web_json(&web_manifest, title, runtime); let progress_html = build_progress_log_from_web_json(&web_manifest); return (status_html, progress_html); } - log::warn!("[TASKMD_HTML] Failed to parse manifest JSON for task: {}", task_id); + log::warn!("Failed to parse manifest JSON for task: {}", task_id); } } - log::info!("[TASKMD_HTML] No manifest found for task: {}", task_id); + log::info!("No manifest found for task: {}", task_id); let default_status = format!(r#"
@@ -326,10 +326,10 @@ fn build_progress_log_html(manifest: &TaskManifest) -> String { let total_steps = manifest.total_steps; - log::info!("[PROGRESS_HTML] Building progress log, {} sections, total_steps={}", manifest.sections.len(), total_steps); + log::info!("Building progress log, {} sections, total_steps={}", manifest.sections.len(), total_steps); for section in &manifest.sections { - log::info!("[PROGRESS_HTML] Section '{}': children={}, items={}, item_groups={}", + log::info!("Section '{}': children={}, items={}, item_groups={}", section.name, section.children.len(), section.items.len(), section.item_groups.len()); let section_class = match section.status { crate::auto_task::SectionStatus::Completed => "completed expanded", @@ -362,7 +362,7 @@ fn build_progress_log_html(manifest: &TaskManifest) -> String { "#, section_class, section.id, section.name, global_current, total_steps, section_class, status_text, section_class)); for child in §ion.children { - log::info!("[PROGRESS_HTML] Child '{}': items={}, item_groups={}", + log::info!(" Child '{}': items={}, item_groups={}", child.name, child.items.len(), child.item_groups.len()); let child_class = match child.status { crate::auto_task::SectionStatus::Completed => "completed expanded",