diff --git a/src/mir/builder/control_flow/debug.rs b/src/mir/builder/control_flow/debug.rs index b3d1ada9..7233d813 100644 --- a/src/mir/builder/control_flow/debug.rs +++ b/src/mir/builder/control_flow/debug.rs @@ -3,21 +3,27 @@ //! This module provides diagnostic tools for tracing and debugging //! control flow behavior during MIR construction. //! +//! # Phase 195: Unified Tracing +//! +//! All JoinIR tracing now goes through the JoinLoopTrace module. +//! See `joinir/trace.rs` for the unified tracing interface. +//! //! # Environment Variables //! //! - `NYASH_TRACE_VARMAP=1` - Enable variable map tracing +//! - `NYASH_JOINIR_DEBUG=1` - Enable general JoinIR debug output +//! - `NYASH_OPTION_C_DEBUG=1` - Enable PHI-related debug +//! - `NYASH_JOINIR_MAINLINE_DEBUG=1` - Enable mainline routing debug +//! - `NYASH_LOOPFORM_DEBUG=1` - Enable LoopForm debug use super::super::MirBuilder; impl MirBuilder { /// Trace variable_map state for debugging + /// + /// Phase 195: Delegates to JoinLoopTrace for unified tracing. /// Enable with NYASH_TRACE_VARMAP=1 pub(in crate::mir::builder) fn trace_varmap(&self, context: &str) { - if std::env::var("NYASH_TRACE_VARMAP").is_ok() { - let vars: Vec<_> = self.variable_map.iter() - .map(|(k, v)| format!("{}={:?}", k, v)) - .collect(); - eprintln!("[varmap/{}] {{{}}}", context, vars.join(", ")); - } + super::joinir::trace::trace().varmap(context, &self.variable_map); } } diff --git a/src/mir/builder/control_flow/joinir/merge/block_allocator.rs b/src/mir/builder/control_flow/joinir/merge/block_allocator.rs index fe1a79dc..ab8a86e6 100644 --- a/src/mir/builder/control_flow/joinir/merge/block_allocator.rs +++ b/src/mir/builder/control_flow/joinir/merge/block_allocator.rs @@ -7,6 +7,7 @@ use crate::mir::MirModule; use crate::mir::builder::joinir_id_remapper::JoinIrIdRemapper; +use super::super::trace; /// Phase 1: Allocate new block IDs for ALL functions (Phase 189) /// @@ -21,20 +22,16 @@ pub(super) fn allocate_blocks( // Create exit block for Return conversion (single for all functions) let _exit_block_id = builder.block_gen.next(); - if debug { - eprintln!( - "[cf_loop/joinir] Phase 189: Allocating block IDs for all functions" - ); - } + // Phase 195: Use unified trace + trace::trace().blocks("allocator", "Phase 189: Allocating block IDs for all functions"); // DETERMINISM FIX: Sort functions by name to ensure consistent iteration order let mut functions: Vec<_> = mir_module.functions.iter().collect(); functions.sort_by_key(|(name, _)| name.as_str()); for (func_name, func) in functions { - if debug { - eprintln!("[cf_loop/joinir] Function: {}", func_name); - } + // Phase 195: Use unified trace + trace::trace().blocks("allocator", &format!("Function: {}", func_name)); // DETERMINISM FIX: Sort blocks by ID to ensure consistent iteration order let mut blocks: Vec<_> = func.blocks.iter().collect(); @@ -45,12 +42,11 @@ pub(super) fn allocate_blocks( // Use remapper to store composite key mapping remapper.set_block(func_name.clone(), *old_block_id, new_block_id); - if debug { - eprintln!( - "[cf_loop/joinir] Block remap: {}:{:?} → {:?}", - func_name, old_block_id, new_block_id - ); - } + // Phase 195: Use unified trace + trace::trace().blocks( + "allocator", + &format!("Block remap: {}:{:?} → {:?}", func_name, old_block_id, new_block_id), + ); } // Map function entry blocks for Call→Jump conversion (stored in remapper for later use) @@ -58,12 +54,11 @@ pub(super) fn allocate_blocks( .get_block(func_name, func.entry_block) .ok_or_else(|| format!("Entry block not found for {}", func_name))?; - if debug { - eprintln!( - "[cf_loop/joinir] Entry map: {} → {:?}", - func_name, entry_block_new - ); - } + // Phase 195: Use unified trace + trace::trace().blocks( + "allocator", + &format!("Entry map: {} → {:?}", func_name, entry_block_new), + ); } Ok(remapper) diff --git a/src/mir/builder/control_flow/joinir/mod.rs b/src/mir/builder/control_flow/joinir/mod.rs index f1d75bca..dcac42d5 100644 --- a/src/mir/builder/control_flow/joinir/mod.rs +++ b/src/mir/builder/control_flow/joinir/mod.rs @@ -4,7 +4,9 @@ //! - Pattern lowerers (patterns/) //! - Routing logic (routing.rs) ✅ //! - MIR block merging (merge/) ✅ Phase 4 +//! - Unified tracing (trace.rs) ✅ Phase 195 pub(in crate::mir::builder) mod patterns; pub(in crate::mir::builder) mod routing; pub(in crate::mir::builder) mod merge; +pub(in crate::mir::builder) mod trace; diff --git a/src/mir/builder/control_flow/joinir/patterns/pattern1_minimal.rs b/src/mir/builder/control_flow/joinir/patterns/pattern1_minimal.rs index 4488cec4..afe222ec 100644 --- a/src/mir/builder/control_flow/joinir/patterns/pattern1_minimal.rs +++ b/src/mir/builder/control_flow/joinir/patterns/pattern1_minimal.rs @@ -3,6 +3,7 @@ use crate::ast::ASTNode; use crate::mir::builder::MirBuilder; use crate::mir::ValueId; +use super::super::trace; /// Phase 194: Detection function for Pattern 1 /// @@ -55,9 +56,8 @@ impl MirBuilder { use crate::mir::BasicBlockId; use std::collections::{BTreeMap, BTreeSet}; - if debug { - eprintln!("[cf_loop/joinir/pattern1] Calling Pattern 1 minimal lowerer"); - } + // Phase 195: Use unified trace + trace::trace().debug("pattern1", "Calling Pattern 1 minimal lowerer"); // Phase 188-Impl-2: Extract loop variable from condition // For `i < 3`, extract `i` and look up its ValueId in variable_map @@ -73,12 +73,8 @@ impl MirBuilder { ) })?; - if debug { - eprintln!( - "[cf_loop/joinir/pattern1] Loop variable '{}' → {:?}", - loop_var_name, loop_var_id - ); - } + // Phase 195: Use unified trace + trace::trace().varmap("pattern1_start", &self.variable_map); // Create a minimal LoopScopeShape (Phase 188: hardcoded for loop_min_while.hako) // Pattern 1 lowerer ignores the scope anyway, so this is just a placeholder @@ -108,19 +104,22 @@ impl MirBuilder { let join_module = match lower_simple_while_minimal(scope, Some(ctx)) { Some(module) => module, None => { - if debug { - eprintln!("[cf_loop/joinir/pattern1] Pattern 1 lowerer returned None"); - } + // Phase 195: Use unified trace + trace::trace().debug("pattern1", "Pattern 1 lowerer returned None"); return Ok(None); } }; - if debug { - eprintln!( - "[cf_loop/joinir/pattern1] JoinModule generated with {} functions", - join_module.functions.len() - ); - } + // Phase 195: Use unified trace + trace::trace().joinir_stats( + "pattern1", + join_module.functions.len(), + join_module + .functions + .values() + .map(|f| f.body.len()) + .sum(), + ); // Convert JoinModule to MirModule // Phase 188: Pass empty meta map since Pattern 1 lowerer doesn't use metadata @@ -130,12 +129,16 @@ impl MirBuilder { let mir_module = convert_join_module_to_mir_with_meta(&join_module, &empty_meta) .map_err(|e| format!("[cf_loop/joinir/pattern1] MIR conversion failed: {:?}", e))?; - if debug { - eprintln!( - "[cf_loop/joinir/pattern1] MirModule generated with {} functions", - mir_module.functions.len() - ); - } + // Phase 195: Use unified trace + trace::trace().joinir_stats( + "pattern1", + mir_module.functions.len(), + mir_module + .functions + .values() + .map(|f| f.blocks.len()) + .sum(), + ); // Merge JoinIR blocks into current function // Phase 188-Impl-3: Create and pass JoinInlineBoundary for Pattern 1 @@ -163,12 +166,8 @@ impl MirBuilder { let void_val = crate::mir::builder::emission::constant::emit_void(self); - if debug { - eprintln!( - "[cf_loop/joinir/pattern1] Loop complete, returning Void {:?}", - void_val - ); - } + // Phase 195: Use unified trace + trace::trace().debug("pattern1", &format!("Loop complete, returning Void {:?}", void_val)); Ok(Some(void_val)) } diff --git a/src/mir/builder/control_flow/joinir/patterns/pattern2_with_break.rs b/src/mir/builder/control_flow/joinir/patterns/pattern2_with_break.rs index 9d9a182d..7a135669 100644 --- a/src/mir/builder/control_flow/joinir/patterns/pattern2_with_break.rs +++ b/src/mir/builder/control_flow/joinir/patterns/pattern2_with_break.rs @@ -3,6 +3,7 @@ use crate::ast::ASTNode; use crate::mir::builder::MirBuilder; use crate::mir::ValueId; +use super::super::trace; /// Phase 194: Detection function for Pattern 2 /// @@ -46,9 +47,8 @@ impl MirBuilder { use crate::mir::BasicBlockId; use std::collections::{BTreeMap, BTreeSet}; - if debug { - eprintln!("[cf_loop/joinir/pattern2] Calling Pattern 2 minimal lowerer"); - } + // Phase 195: Use unified trace + trace::trace().debug("pattern2", "Calling Pattern 2 minimal lowerer"); // Phase 188-Impl-2: Extract loop variable from condition // For `i < 3`, extract `i` and look up its ValueId in variable_map @@ -64,12 +64,8 @@ impl MirBuilder { ) })?; - if debug { - eprintln!( - "[cf_loop/joinir/pattern2] Loop variable '{}' → {:?}", - loop_var_name, loop_var_id - ); - } + // Phase 195: Use unified trace + trace::trace().varmap("pattern2_start", &self.variable_map); // Create a minimal LoopScopeShape (Phase 188: hardcoded for joinir_min_loop.hako) // Pattern 2 lowerer ignores the scope anyway, so this is just a placeholder @@ -91,19 +87,18 @@ impl MirBuilder { let join_module = match lower_loop_with_break_minimal(scope) { Some(module) => module, None => { - if debug { - eprintln!("[cf_loop/joinir/pattern2] Pattern 2 lowerer returned None"); - } + // Phase 195: Use unified trace + trace::trace().debug("pattern2", "Pattern 2 lowerer returned None"); return Ok(None); } }; - if debug { - eprintln!( - "[cf_loop/joinir/pattern2] JoinModule generated with {} functions", - join_module.functions.len() - ); - } + // Phase 195: Use unified trace + trace::trace().joinir_stats( + "pattern2", + join_module.functions.len(), + join_module.functions.values().map(|f| f.body.len()).sum(), + ); // Convert JoinModule to MirModule // Phase 188: Pass empty meta map since Pattern 2 lowerer doesn't use metadata @@ -113,12 +108,12 @@ impl MirBuilder { let mir_module = convert_join_module_to_mir_with_meta(&join_module, &empty_meta) .map_err(|e| format!("[cf_loop/joinir/pattern2] MIR conversion failed: {:?}", e))?; - if debug { - eprintln!( - "[cf_loop/joinir/pattern2] MirModule generated with {} functions", - mir_module.functions.len() - ); - } + // Phase 195: Use unified trace + trace::trace().joinir_stats( + "pattern2", + mir_module.functions.len(), + mir_module.functions.values().map(|f| f.blocks.len()).sum(), + ); // Merge JoinIR blocks into current function // Phase 188-Impl-2: Create and pass JoinInlineBoundary for Pattern 2 @@ -133,12 +128,8 @@ impl MirBuilder { // The subsequent "return i" statement will emit its own Load + Return let void_val = crate::mir::builder::emission::constant::emit_void(self); - if debug { - eprintln!( - "[cf_loop/joinir/pattern2] Loop complete, returning Void {:?}", - void_val - ); - } + // Phase 195: Use unified trace + trace::trace().debug("pattern2", &format!("Loop complete, returning Void {:?}", void_val)); Ok(Some(void_val)) } diff --git a/src/mir/builder/control_flow/joinir/patterns/pattern3_with_if_phi.rs b/src/mir/builder/control_flow/joinir/patterns/pattern3_with_if_phi.rs index 5e2d0f27..8d826b51 100644 --- a/src/mir/builder/control_flow/joinir/patterns/pattern3_with_if_phi.rs +++ b/src/mir/builder/control_flow/joinir/patterns/pattern3_with_if_phi.rs @@ -3,6 +3,7 @@ use crate::ast::ASTNode; use crate::mir::builder::MirBuilder; use crate::mir::ValueId; +use super::super::trace; /// Phase 194: Detection function for Pattern 3 /// @@ -50,9 +51,8 @@ impl MirBuilder { use crate::mir::BasicBlockId; use std::collections::{BTreeMap, BTreeSet}; - if debug { - eprintln!("[cf_loop/joinir/pattern3] Calling Pattern 3 minimal lowerer"); - } + // Phase 195: Use unified trace + trace::trace().debug("pattern3", "Calling Pattern 3 minimal lowerer"); // Phase 188-Impl-3: Extract loop variable from condition // For `i <= 5`, extract `i` and look up its ValueId in variable_map @@ -80,12 +80,8 @@ impl MirBuilder { ) })?; - if debug { - eprintln!( - "[cf_loop/joinir/pattern3] Loop variables: '{}' → {:?}, 'sum' → {:?}", - loop_var_name, loop_var_id, sum_var_id - ); - } + // Phase 195: Use unified trace + trace::trace().varmap("pattern3_start", &self.variable_map); // Create a minimal LoopScopeShape (Phase 188: hardcoded for loop_if_phi.hako) // Pattern 3 lowerer ignores the scope anyway, so this is just a placeholder @@ -107,19 +103,18 @@ impl MirBuilder { let join_module = match lower_loop_with_if_phi_pattern(scope) { Some(module) => module, None => { - if debug { - eprintln!("[cf_loop/joinir/pattern3] Pattern 3 lowerer returned None"); - } + // Phase 195: Use unified trace + trace::trace().debug("pattern3", "Pattern 3 lowerer returned None"); return Ok(None); } }; - if debug { - eprintln!( - "[cf_loop/joinir/pattern3] JoinModule generated with {} functions", - join_module.functions.len() - ); - } + // Phase 195: Use unified trace + trace::trace().joinir_stats( + "pattern3", + join_module.functions.len(), + join_module.functions.values().map(|f| f.body.len()).sum(), + ); // Convert JoinModule to MirModule // Phase 188: Pass empty meta map since Pattern 3 lowerer doesn't use metadata @@ -129,12 +124,12 @@ impl MirBuilder { let mir_module = convert_join_module_to_mir_with_meta(&join_module, &empty_meta) .map_err(|e| format!("[cf_loop/joinir/pattern3] MIR conversion failed: {:?}", e))?; - if debug { - eprintln!( - "[cf_loop/joinir/pattern3] MirModule generated with {} functions", - mir_module.functions.len() - ); - } + // Phase 195: Use unified trace + trace::trace().joinir_stats( + "pattern3", + mir_module.functions.len(), + mir_module.functions.values().map(|f| f.blocks.len()).sum(), + ); // Merge JoinIR blocks into current function // Phase 190: Use explicit LoopExitBinding for Pattern 3 @@ -159,12 +154,8 @@ impl MirBuilder { // この関数では Void を返すだけでよい（戻り値は後続の `return sum` が扱う）。 let void_val = crate::mir::builder::emission::constant::emit_void(self); - if debug { - eprintln!( - "[cf_loop/joinir/pattern3] Loop complete, returning Void {:?}", - void_val - ); - } + // Phase 195: Use unified trace + trace::trace().debug("pattern3", &format!("Loop complete, returning Void {:?}", void_val)); Ok(Some(void_val)) } diff --git a/src/mir/builder/control_flow/joinir/patterns/router.rs b/src/mir/builder/control_flow/joinir/patterns/router.rs index 1bcca0df..11f44726 100644 --- a/src/mir/builder/control_flow/joinir/patterns/router.rs +++ b/src/mir/builder/control_flow/joinir/patterns/router.rs @@ -115,23 +115,23 @@ pub fn route_loop_pattern( builder: &mut MirBuilder, ctx: &LoopPatternContext, ) -> Result, String> { + use super::super::trace; + // Patterns are already sorted by priority in the table // (Pattern 3 with priority 30 comes first, then Pattern 1 with priority 10, etc.) // This ensures Pattern 3 is checked before Pattern 1, avoiding incorrect routing. for entry in LOOP_PATTERNS { if (entry.detect)(builder, ctx) { - // Log which pattern matched (for debugging) - if ctx.debug || std::env::var("NYASH_TRACE_VARMAP").is_ok() { - eprintln!("[route] Pattern '{}' matched for function '{}'", entry.name, ctx.func_name); - } + // Phase 195: Use unified trace for pattern matching + trace::trace().pattern("route", entry.name, true); return (entry.lower)(builder, ctx); } } // No pattern matched - fall through to legacy path if ctx.debug { - eprintln!("[route] No pattern matched for function '{}', falling back to legacy", ctx.func_name); + trace::trace().debug("route", &format!("No pattern matched for function '{}', falling back to legacy", ctx.func_name)); } Ok(None) } diff --git a/src/mir/builder/control_flow/joinir/routing.rs b/src/mir/builder/control_flow/joinir/routing.rs index e10618d5..8428fe2e 100644 --- a/src/mir/builder/control_flow/joinir/routing.rs +++ b/src/mir/builder/control_flow/joinir/routing.rs @@ -3,6 +3,7 @@ use crate::ast::ASTNode; use crate::mir::builder::MirBuilder; use crate::mir::ValueId; +use super::trace; impl MirBuilder { /// Phase 49: Try JoinIR Frontend for mainline integration @@ -31,12 +32,8 @@ impl MirBuilder { .map(|f| f.signature.name.clone()) .unwrap_or_default(); - eprintln!("[cf_loop/joinir/router] try_cf_loop_joinir called for function: '{}'", func_name); - - // Phase 188-Impl-3: Debug logging for function name routing - if std::env::var("NYASH_JOINIR_MAINLINE_DEBUG").is_ok() { - eprintln!("[cf_loop/joinir/router] Current function name: '{}'", func_name); - } + // Phase 195: Use unified trace + trace::trace().routing("router", &func_name, "try_cf_loop_joinir called"); // Phase 49-4 + Phase 80: Multi-target routing // - Core ON なら代表2本（print_tokens / ArrayExt.filter）は JoinIR を優先し、失敗したら LoopBuilder へフォールバック @@ -75,18 +72,9 @@ impl MirBuilder { } // Debug log when routing through JoinIR Frontend - let debug = std::env::var("NYASH_LOOPFORM_DEBUG").is_ok() - || std::env::var("NYASH_JOINIR_MAINLINE_DEBUG").is_ok(); - eprintln!("[cf_loop/joinir] DEBUG FLAG STATUS: debug={}, NYASH_LOOPFORM_DEBUG={:?}, NYASH_JOINIR_MAINLINE_DEBUG={:?}", - debug, - std::env::var("NYASH_LOOPFORM_DEBUG"), - std::env::var("NYASH_JOINIR_MAINLINE_DEBUG")); - if debug { - eprintln!( - "[cf_loop/joinir] Routing {} through JoinIR Frontend mainline", - func_name - ); - } + // Phase 195: Check trace flags directly from JoinLoopTrace + let debug = trace::trace().is_loopform_enabled() || trace::trace().is_mainline_enabled(); + trace::trace().routing("router", &func_name, "Routing through JoinIR Frontend mainline"); // Phase 49-3: Implement JoinIR Frontend integration self.cf_loop_joinir_impl(condition, body, &func_name, debug) @@ -130,37 +118,33 @@ impl MirBuilder { let ctx = LoopPatternContext::new(condition, body, &func_name, debug); if let Some(result) = route_loop_pattern(self, &ctx)? { - if debug { - eprintln!("[cf_loop/joinir] Pattern router succeeded for '{}'", func_name); - } + // Phase 195: Use unified trace + trace::trace().routing("router", func_name, "Pattern router succeeded"); return Ok(Some(result)); } - if debug { - eprintln!("[cf_loop/joinir] Pattern router found no match for '{}', continuing to legacy path", func_name); - } + // Phase 195: Use unified trace + trace::trace().routing("router", func_name, "Pattern router found no match, continuing to legacy path"); // Phase 50: Create appropriate binding based on function name let binding = match func_name { "JsonTokenizer.print_tokens/0" => LoopFrontendBinding::for_print_tokens(), "ArrayExtBox.filter/2" => LoopFrontendBinding::for_array_filter(), _ => { - if debug { - eprintln!( - "[cf_loop/joinir] No binding defined for {}, falling back", - func_name - ); - } + // Phase 195: Use unified trace + trace::trace().routing("router", func_name, "No binding defined, falling back"); return Ok(None); } }; - if debug { - eprintln!( - "[cf_loop/joinir] Using binding: counter={}, acc={:?}, pattern={:?}", - binding.counter_var, binding.accumulator_var, binding.pattern - ); - } + // Phase 195: Use unified trace + trace::trace().debug( + "router", + &format!( + "Using binding for '{}': counter={}, acc={:?}, pattern={:?}", + func_name, binding.counter_var, binding.accumulator_var, binding.pattern + ), + ); // Step 1: Convert condition and body to JSON let condition_json = ast_to_json(condition); @@ -178,9 +162,8 @@ impl MirBuilder { // Phase 52: Add 'me' for instance methods if binding.needs_me_receiver() { - if debug { - eprintln!("[cf_loop/joinir] Adding 'me' to params (instance method)"); - } + // Phase 195: Use unified trace + trace::trace().debug("router", "Adding 'me' to params (instance method)"); params.push(serde_json::json!("me")); } @@ -190,12 +173,8 @@ impl MirBuilder { if ext_ref == "me" || ext_ref.starts_with("me.") { continue; } - if debug { - eprintln!( - "[cf_loop/joinir] Adding '{}' to params (external_ref)", - ext_ref - ); - } + // Phase 195: Use unified trace + trace::trace().debug("router", &format!("Adding '{}' to params (external_ref)", ext_ref)); params.push(serde_json::json!(ext_ref)); } @@ -230,13 +209,15 @@ impl MirBuilder { ] }); - if debug { - eprintln!( - "[cf_loop/joinir] Generated JSON v0 for {}: {}", + // Phase 195: Use unified trace + trace::trace().debug( + "router", + &format!( + "Generated JSON v0 for {}: {}", func_name, serde_json::to_string_pretty(&program_json).unwrap_or_default() - ); - } + ), + ); // Step 3: Lower to JoinIR // Phase 49-4: Use catch_unwind for graceful fallback on unsupported patterns @@ -261,12 +242,14 @@ impl MirBuilder { "unknown panic".to_string() }; - if debug { - eprintln!( - "[cf_loop/joinir] JoinIR lowering failed for {}: {}, falling back to legacy", + // Phase 195: Use unified trace + trace::trace().debug( + "router", + &format!( + "JoinIR lowering failed for {}: {}, falling back to legacy", func_name, panic_msg - ); - } + ), + ); // Return None to fall back to legacy LoopBuilder return Ok(None); } @@ -275,38 +258,48 @@ impl MirBuilder { // Phase 49-3 MVP: Use empty meta map (full if-analysis is Phase 40+ territory) let join_meta = JoinFuncMetaMap::new(); - if debug { - eprintln!( - "[cf_loop/joinir] JoinModule has {} functions, entry={:?}", - join_module.functions.len(), - join_module.entry - ); - } + // Phase 195: Use unified trace + trace::trace().joinir_stats( + "router", + join_module.functions.len(), + join_module + .functions + .values() + .map(|f| f.body.len()) + .sum(), + ); // Step 4: Convert JoinModule to MIR let mir_module = convert_join_module_to_mir_with_meta(&join_module, &join_meta) .map_err(|e| format!("JoinIR→MIR conversion failed: {}", e.message))?; - if debug { - eprintln!( - "[cf_loop/joinir] MirModule has {} functions", - mir_module.functions.len() + // Phase 195: Use unified trace for MIR module stats + if trace::trace().is_joinir_enabled() { + trace::trace().debug( + "router", + &format!("MirModule has {} functions", mir_module.functions.len()), ); for (name, func) in &mir_module.functions { - eprintln!( - "[cf_loop/joinir] - {}: {} blocks, entry={:?}", - name, - func.blocks.len(), - func.entry_block + trace::trace().debug( + "router", + &format!( + " - {}: {} blocks, entry={:?}", + name, + func.blocks.len(), + func.entry_block + ), ); // Phase 189: Debug - show block contents for (block_id, block) in &func.blocks { - eprintln!("[cf_loop/joinir] Block {:?}: {} instructions", block_id, block.instructions.len()); + trace::trace().blocks( + "router", + &format!("Block {:?}: {} instructions", block_id, block.instructions.len()), + ); for (i, inst) in block.instructions.iter().enumerate() { - eprintln!("[cf_loop/joinir] [{}] {:?}", i, inst); + trace::trace().instructions("router", &format!("[{}] {:?}", i, inst)); } if let Some(ref term) = block.terminator { - eprintln!("[cf_loop/joinir] terminator: {:?}", term); + trace::trace().instructions("router", &format!("terminator: {:?}", term)); } } } diff --git a/src/mir/builder/control_flow/joinir/trace.rs b/src/mir/builder/control_flow/joinir/trace.rs new file mode 100644 index 00000000..6619f831 --- /dev/null +++ b/src/mir/builder/control_flow/joinir/trace.rs @@ -0,0 +1,250 @@ +//! JoinLoopTrace - Unified tracing for JoinIR loop lowering +//! +//! This module consolidates all debug output for JoinIR loop operations into a single +//! interface, making tracing consistent and controllable through environment variables. +//! +//! # Environment Variables +//! +//! - `NYASH_TRACE_VARMAP=1`: Enable variable_map tracing (shows variable → ValueId mappings) +//! - `NYASH_JOINIR_DEBUG=1`: Enable general JoinIR debug output (pattern routing, merge stats) +//! - `NYASH_OPTION_C_DEBUG=1`: Enable PHI-related debug (Option C PHI generation) +//! - `NYASH_JOINIR_MAINLINE_DEBUG=1`: Enable mainline routing debug (function name matching) +//! - `NYASH_LOOPFORM_DEBUG=1`: Enable LoopForm debug (control flow structure) +//! +//! # Output Format +//! +//! All trace output uses prefixed tags for easy filtering: +//! +//! ```text +//! [trace:pattern] route: Pattern3_WithIfPhi MATCHED +//! [trace:varmap] pattern3_before_merge: i→r4, sum→r7 +//! [trace:joinir] merge_start: 3 functions, 45 blocks +//! [trace:phi] pattern3: PHI already exists, skipping +//! [trace:merge] pattern3: starting JoinIR merge +//! [trace:exit_phi] pattern3: sum r7→r15 +//! [trace:debug] router: Current function name: 'main' +//! ``` +//! +//! # Examples +//! +//! ```bash +//! # Enable variable_map tracing only +//! NYASH_TRACE_VARMAP=1 ./target/release/hakorune test.hako 2>&1 | grep "\[trace:" +//! +//! # Enable all JoinIR debug output +//! NYASH_JOINIR_DEBUG=1 ./target/release/hakorune test.hako 2>&1 | grep "\[trace:" +//! +//! # Enable PHI tracing +//! NYASH_OPTION_C_DEBUG=1 ./target/release/hakorune test.hako 2>&1 | grep "\[trace:phi\]" +//! +//! # Enable multiple trace categories +//! NYASH_TRACE_VARMAP=1 NYASH_JOINIR_DEBUG=1 ./target/release/hakorune test.hako +//! ``` + +use std::collections::BTreeMap; +use crate::mir::ValueId; + +/// Unified tracer for JoinIR loop operations. +/// +/// Consolidates all debug output through a single interface, reading environment +/// variables to control which trace categories are enabled. +pub struct JoinLoopTrace { + /// Whether varmap tracing is enabled (NYASH_TRACE_VARMAP) + varmap_enabled: bool, + /// Whether general JoinIR debug is enabled (NYASH_JOINIR_DEBUG) + joinir_enabled: bool, + /// Whether PHI debug is enabled (NYASH_OPTION_C_DEBUG) + phi_enabled: bool, + /// Whether mainline routing debug is enabled (NYASH_JOINIR_MAINLINE_DEBUG) + mainline_enabled: bool, + /// Whether LoopForm debug is enabled (NYASH_LOOPFORM_DEBUG) + loopform_enabled: bool, +} + +impl JoinLoopTrace { + /// Create a new tracer, reading environment variables. + pub fn new() -> Self { + Self { + varmap_enabled: std::env::var("NYASH_TRACE_VARMAP").is_ok(), + joinir_enabled: std::env::var("NYASH_JOINIR_DEBUG").is_ok(), + phi_enabled: std::env::var("NYASH_OPTION_C_DEBUG").is_ok(), + mainline_enabled: std::env::var("NYASH_JOINIR_MAINLINE_DEBUG").is_ok(), + loopform_enabled: std::env::var("NYASH_LOOPFORM_DEBUG").is_ok(), + } + } + + /// Check if any tracing is enabled + pub fn is_enabled(&self) -> bool { + self.varmap_enabled + || self.joinir_enabled + || self.phi_enabled + || self.mainline_enabled + || self.loopform_enabled + } + + /// Check if varmap tracing is enabled + pub fn is_varmap_enabled(&self) -> bool { + self.varmap_enabled + } + + /// Check if general joinir debug is enabled + pub fn is_joinir_enabled(&self) -> bool { + self.joinir_enabled + } + + /// Check if mainline routing debug is enabled + pub fn is_mainline_enabled(&self) -> bool { + self.mainline_enabled + } + + /// Check if loopform debug is enabled (legacy compatibility) + pub fn is_loopform_enabled(&self) -> bool { + self.loopform_enabled + } + + /// Trace pattern detection/selection + /// + /// # Arguments + /// - `tag`: Context identifier (e.g., "route", "pattern3") + /// - `pattern_name`: Name of the pattern (e.g., "Pattern3_WithIfPhi") + /// - `matched`: Whether the pattern matched (true) or was skipped (false) + pub fn pattern(&self, tag: &str, pattern_name: &str, matched: bool) { + if self.joinir_enabled || self.varmap_enabled { + let status = if matched { "MATCHED" } else { "skipped" }; + eprintln!("[trace:pattern] {}: {} {}", tag, pattern_name, status); + } + } + + /// Trace variable_map state + /// + /// # Arguments + /// - `tag`: Context identifier (e.g., "pattern3_before_merge", "after_phi") + /// - `vars`: The variable_map to display (variable name → ValueId) + pub fn varmap(&self, tag: &str, vars: &BTreeMap) { + if self.varmap_enabled { + let entries: Vec = vars + .iter() + .map(|(k, v)| format!("{}→r{}", k, v.0)) + .collect(); + eprintln!("[trace:varmap] {}: {}", tag, entries.join(", ")); + } + } + + /// Trace JoinIR function/block counts + /// + /// # Arguments + /// - `tag`: Context identifier (e.g., "merge_start", "after_allocation") + /// - `func_count`: Number of functions in the JoinModule + /// - `block_count`: Total number of blocks across all functions + pub fn joinir_stats(&self, tag: &str, func_count: usize, block_count: usize) { + if self.joinir_enabled { + eprintln!( + "[trace:joinir] {}: {} functions, {} blocks", + tag, func_count, block_count + ); + } + } + + /// Trace PHI operations + /// + /// # Arguments + /// - `tag`: Context identifier (e.g., "pattern3", "exit_block") + /// - `msg`: Human-readable message about the PHI operation + pub fn phi(&self, tag: &str, msg: &str) { + if self.phi_enabled { + eprintln!("[trace:phi] {}: {}", tag, msg); + } + } + + /// Trace merge operations + /// + /// # Arguments + /// - `tag`: Context identifier (e.g., "pattern3", "block_allocation") + /// - `msg`: Human-readable message about the merge operation + pub fn merge(&self, tag: &str, msg: &str) { + if self.joinir_enabled || self.varmap_enabled { + eprintln!("[trace:merge] {}: {}", tag, msg); + } + } + + /// Trace exit PHI connection (variable_map update) + /// + /// # Arguments + /// - `tag`: Context identifier (e.g., "pattern3", "exit_reconnect") + /// - `var_name`: Name of the variable being reconnected + /// - `old_id`: Old ValueId (before exit PHI) + /// - `new_id`: New ValueId (after exit PHI) + pub fn exit_phi(&self, tag: &str, var_name: &str, old_id: ValueId, new_id: ValueId) { + if self.varmap_enabled { + eprintln!( + "[trace:exit_phi] {}: {} r{}→r{}", + tag, var_name, old_id.0, new_id.0 + ); + } + } + + /// Generic debug message (only if any tracing enabled) + /// + /// # Arguments + /// - `tag`: Context identifier (e.g., "router", "pattern1") + /// - `msg`: Human-readable debug message + pub fn debug(&self, tag: &str, msg: &str) { + if self.is_enabled() { + eprintln!("[trace:debug] {}: {}", tag, msg); + } + } + + /// Trace function routing decisions + /// + /// # Arguments + /// - `tag`: Context identifier (e.g., "router", "mainline") + /// - `func_name`: Name of the function being routed + /// - `msg`: Human-readable message about the routing decision + pub fn routing(&self, tag: &str, func_name: &str, msg: &str) { + if self.joinir_enabled || self.mainline_enabled { + eprintln!("[trace:routing] {}: function '{}' - {}", tag, func_name, msg); + } + } + + /// Trace block allocation and remapping + /// + /// # Arguments + /// - `tag`: Context identifier (e.g., "allocator", "remap") + /// - `msg`: Human-readable message about block operations + pub fn blocks(&self, tag: &str, msg: &str) { + if self.joinir_enabled { + eprintln!("[trace:blocks] {}: {}", tag, msg); + } + } + + /// Trace instruction rewriting + /// + /// # Arguments + /// - `tag`: Context identifier (e.g., "rewriter", "phi_inject") + /// - `msg`: Human-readable message about instruction operations + pub fn instructions(&self, tag: &str, msg: &str) { + if self.joinir_enabled { + eprintln!("[trace:instructions] {}: {}", tag, msg); + } + } +} + +impl Default for JoinLoopTrace { + fn default() -> Self { + Self::new() + } +} + +/// Global singleton for easy access (lazy initialized) +/// +/// This provides a convenient way to access the tracer without passing it around: +/// +/// ```rust +/// trace::trace().varmap("my_tag", &variable_map); +/// trace::trace().pattern("route", "Pattern1_Minimal", true); +/// ``` +pub fn trace() -> &'static JoinLoopTrace { + use std::sync::OnceLock; + static TRACE: OnceLock = OnceLock::new(); + TRACE.get_or_init(JoinLoopTrace::new) +}