refactor(builder): route debug logs via trace

This commit is contained in:
nyash-codex
2025-12-18 00:29:57 +09:00
parent 2b5c141e22
commit e65bb791b9
5 changed files with 177 additions and 79 deletions

View File

@ -427,19 +427,38 @@ impl MirBuilder {
// Debug trace
if std::env::var("NYASH_STATIC_CALL_TRACE").ok().as_deref() == Some("1") {
eprintln!(
"[DEBUG] try_build_static_method_call: obj_name={}, method={}",
obj_name, method
let trace = crate::mir::builder::control_flow::joinir::trace::trace();
trace.stderr_if(
&format!(
"[DEBUG] try_build_static_method_call: obj_name={}, method={}",
obj_name, method
),
true,
);
eprintln!("[DEBUG] is_local_var={}", is_local_var);
trace.stderr_if(&format!("[DEBUG] is_local_var={}", is_local_var), true);
if is_local_var {
eprintln!("[DEBUG] variable_map contains '{}' - treating as local variable, will use method call", obj_name);
eprintln!(
"[DEBUG] variable_map keys: {:?}",
self.variable_ctx.variable_map.keys().collect::<Vec<_>>()
trace.stderr_if(
&format!(
"[DEBUG] variable_map contains '{}' - treating as local variable, will use method call",
obj_name
),
true,
);
trace.stderr_if(
&format!(
"[DEBUG] variable_map keys: {:?}",
self.variable_ctx.variable_map.keys().collect::<Vec<_>>()
),
true,
);
} else {
eprintln!("[DEBUG] '{}' not in variable_map - treating as static box, will use global call", obj_name);
trace.stderr_if(
&format!(
"[DEBUG] '{}' not in variable_map - treating as static box, will use global call",
obj_name
),
true,
);
}
}
@ -565,30 +584,43 @@ impl MirBuilder {
fn trace_receiver_if_enabled(&self, object: &ASTNode, object_value: ValueId) {
if std::env::var("NYASH_DEBUG_PARAM_RECEIVER").ok().as_deref() == Some("1") {
if let ASTNode::Variable { name, .. } = object {
eprintln!(
"[DEBUG/param-recv] build_method_call receiver '{}' → ValueId({})",
name, object_value.0
let trace = crate::mir::builder::control_flow::joinir::trace::trace();
trace.stderr_if(
&format!(
"[DEBUG/param-recv] build_method_call receiver '{}' → ValueId({})",
name, object_value.0
),
true,
);
if let Some(origin) = self.type_ctx.value_origin_newbox.get(&object_value) {
eprintln!("[DEBUG/param-recv] origin: {}", origin);
trace.stderr_if(&format!("[DEBUG/param-recv] origin: {}", origin), true);
}
if let Some(&mapped_id) = self.variable_ctx.variable_map.get(name) {
eprintln!(
"[DEBUG/param-recv] variable_map['{}'] = ValueId({})",
name, mapped_id.0
trace.stderr_if(
&format!(
"[DEBUG/param-recv] variable_map['{}'] = ValueId({})",
name, mapped_id.0
),
true,
);
if mapped_id != object_value {
eprintln!("[DEBUG/param-recv] ⚠️ MISMATCH! build_expression returned different ValueId!");
trace.stderr_if(
"[DEBUG/param-recv] ⚠️ MISMATCH! build_expression returned different ValueId!",
true,
);
}
} else {
eprintln!(
"[DEBUG/param-recv] ⚠️ '{}' NOT FOUND in variable_map!",
name
trace.stderr_if(
&format!(
"[DEBUG/param-recv] ⚠️ '{}' NOT FOUND in variable_map!",
name
),
true,
);
}
eprintln!(
"[DEBUG/param-recv] current_block: {:?}",
self.current_block
trace.stderr_if(
&format!("[DEBUG/param-recv] current_block: {:?}", self.current_block),
true,
);
}
}

View File

@ -83,11 +83,19 @@ impl MirBuilder {
ctx.saved_function = self.scope_ctx.current_function.take();
ctx.saved_block = self.current_block.take();
eprintln!(
"[DEBUG/create_function_skeleton] Creating function: {}",
func_name
let trace = crate::mir::builder::control_flow::joinir::trace::trace();
trace.emit_if(
"debug",
"create_function_skeleton",
&format!("Creating function: {}", func_name),
trace.is_enabled(),
);
trace.emit_if(
"debug",
"create_function_skeleton",
&format!("Entry block: {:?}", entry),
trace.is_enabled(),
);
eprintln!("[DEBUG/create_function_skeleton] Entry block: {:?}", entry);
// Phase 136 Step 3/7: Use scope_ctx as SSOT
self.scope_ctx.current_function = Some(function);
@ -166,17 +174,33 @@ impl MirBuilder {
/// 🎯 箱理論: Step 4 - 本体lowering
fn lower_function_body(&mut self, body: Vec<ASTNode>) -> Result<(), String> {
let trace = crate::mir::builder::control_flow::joinir::trace::trace();
if crate::config::env::joinir_dev_enabled() {
let tree = crate::mir::control_tree::StepTreeBuilderBox::build_from_block(&body);
crate::mir::builder::control_flow::joinir::trace::trace()
.dev("control_tree/step_tree", &tree.to_compact_string());
trace.dev("control_tree/step_tree", &tree.to_compact_string());
}
eprintln!("[DEBUG/lower_function_body] body.len() = {}", body.len());
trace.emit_if(
"debug",
"lower_function_body",
&format!("body.len() = {}", body.len()),
trace.is_enabled(),
);
let program_ast = function_lowering::wrap_in_program(body);
eprintln!("[DEBUG/lower_function_body] About to call build_expression");
trace.emit_if(
"debug",
"lower_function_body",
"About to call build_expression",
trace.is_enabled(),
);
let _last = self.build_expression(program_ast)?;
eprintln!("[DEBUG/lower_function_body] build_expression completed");
trace.emit_if(
"debug",
"lower_function_body",
"build_expression completed",
trace.is_enabled(),
);
Ok(())
}

View File

@ -39,17 +39,19 @@ impl super::MirBuilder {
.as_deref()
== Some("1")
{
let trace = crate::mir::builder::control_flow::joinir::trace::trace();
// NamingBox SSOT: Use encode_static_method for main/arity entry
let func_name =
crate::mir::naming::encode_static_method(&box_name, "main", params.len());
eprintln!(
"[DEBUG] build_static_main_box: Before lower_static_method_as_function"
trace.stderr_if(
"[DEBUG] build_static_main_box: Before lower_static_method_as_function",
true,
);
eprintln!("[DEBUG] params.len() = {}", params.len());
eprintln!("[DEBUG] body.len() = {}", body.len());
eprintln!(
"[DEBUG] variable_map = {:?}",
self.variable_ctx.variable_map
trace.stderr_if(&format!("[DEBUG] params.len() = {}", params.len()), true);
trace.stderr_if(&format!("[DEBUG] body.len() = {}", body.len()), true);
trace.stderr_if(
&format!("[DEBUG] variable_map = {:?}", self.variable_ctx.variable_map),
true,
);
// Note: Metadata clearing is now handled by BoxCompilationContext (箱理論)
// See lifecycle.rs and builder_calls.rs for context swap implementation
@ -58,12 +60,13 @@ impl super::MirBuilder {
params.clone(),
body.clone(),
);
eprintln!(
"[DEBUG] build_static_main_box: After lower_static_method_as_function"
trace.stderr_if(
"[DEBUG] build_static_main_box: After lower_static_method_as_function",
true,
);
eprintln!(
"[DEBUG] variable_map = {:?}",
self.variable_ctx.variable_map
trace.stderr_if(
&format!("[DEBUG] variable_map = {:?}", self.variable_ctx.variable_map),
true,
);
}
// Initialize local variables for Main.main() parameters

View File

@ -152,9 +152,12 @@ impl BoundaryInjector {
copy_instructions.push(copy_inst);
if debug {
eprintln!(
"[BoundaryInjector] Join input: Copy {:?} = Copy {:?}",
remapped_join, remapped_host
crate::mir::builder::control_flow::joinir::trace::trace().stderr_if(
&format!(
"[BoundaryInjector] Join input: Copy {:?} = Copy {:?}",
remapped_join, remapped_host
),
true,
);
}
}
@ -162,12 +165,18 @@ impl BoundaryInjector {
// Phase 177-3 DEBUG: Check value_map in BoundaryInjector
if debug {
eprintln!("[DEBUG-177] === BoundaryInjector value_map ===");
crate::mir::builder::control_flow::joinir::trace::trace().stderr_if(
"[DEBUG-177] === BoundaryInjector value_map ===",
true,
);
for binding in &boundary.condition_bindings {
let lookup = value_map.get(&binding.join_value);
eprintln!(
"[DEBUG-177] '{}': JoinIR {:?}{:?}",
binding.name, binding.join_value, lookup
crate::mir::builder::control_flow::joinir::trace::trace().stderr_if(
&format!(
"[DEBUG-177] '{}': JoinIR {:?}{:?}",
binding.name, binding.join_value, lookup
),
true,
);
}
}

View File

@ -167,6 +167,7 @@ impl super::MirBuilder {
// Block: sequentially build statements and return last value or Void
pub(super) fn build_block(&mut self, statements: Vec<ASTNode>) -> Result<ValueId, String> {
let trace = crate::mir::builder::control_flow::joinir::trace::trace();
// Scope hint for bare block (Program)
let scope_id = self.current_block.map(|bb| bb.as_u32()).unwrap_or(0);
self.hint_scope_enter(scope_id);
@ -174,26 +175,38 @@ impl super::MirBuilder {
let mut last_value = None;
let total = statements.len();
eprintln!("[DEBUG/build_block] Processing {} statements", total);
trace.emit_if(
"debug",
"build_block",
&format!("Processing {} statements", total),
trace.is_enabled(),
);
for (idx, statement) in statements.into_iter().enumerate() {
eprintln!(
"[DEBUG/build_block] Statement {}/{} current_block={:?} current_function={}",
idx + 1,
total,
self.current_block,
self.scope_ctx
.current_function
.as_ref()
.map(|f| f.signature.name.as_str())
.unwrap_or("none")
trace.emit_if(
"debug",
"build_block",
&format!(
"Statement {}/{} current_block={:?} current_function={}",
idx + 1,
total,
self.current_block,
self.scope_ctx
.current_function
.as_ref()
.map(|f| f.signature.name.as_str())
.unwrap_or("none")
),
trace.is_enabled(),
);
last_value = Some(self.build_statement(statement)?);
// If the current block was terminated by this statement (e.g., return/throw),
// do not emit any further instructions for this block.
if is_current_block_terminated(self)? {
eprintln!(
"[DEBUG/build_block] Block terminated after statement {}",
idx + 1
trace.emit_if(
"debug",
"build_block",
&format!("Block terminated after statement {}", idx + 1),
trace.is_enabled(),
);
break;
}
@ -206,7 +219,12 @@ impl super::MirBuilder {
if !self.is_current_block_terminated() {
self.hint_scope_leave(scope_id);
}
eprintln!("[DEBUG/build_block] Completed, returning value {:?}", out);
trace.emit_if(
"debug",
"build_block",
&format!("Completed, returning value {:?}", out),
trace.is_enabled(),
);
Ok(out)
}
@ -288,10 +306,13 @@ impl super::MirBuilder {
initial_values: Vec<Option<Box<ASTNode>>>,
) -> Result<ValueId, String> {
if std::env::var("NYASH_LOOPFORM_DEBUG").is_ok() {
eprintln!(
"[build_local_statement] ENTRY: variables={:?}, initial_values.len()={}",
variables,
initial_values.len()
crate::mir::builder::control_flow::joinir::trace::trace().stderr_if(
&format!(
"[build_local_statement] ENTRY: variables={:?}, initial_values.len()={}",
variables,
initial_values.len()
),
true,
);
}
let mut last_value = None;
@ -306,9 +327,12 @@ impl super::MirBuilder {
let var_id = self.next_value_id();
if std::env::var("NYASH_LOOPFORM_DEBUG").is_ok() {
eprintln!(
"[build_local_statement] '{}': init_val={:?}, allocated var_id={:?}",
var_name, init_val, var_id
crate::mir::builder::control_flow::joinir::trace::trace().stderr_if(
&format!(
"[build_local_statement] '{}': init_val={:?}, allocated var_id={:?}",
var_name, init_val, var_id
),
true,
);
}
@ -325,18 +349,24 @@ impl super::MirBuilder {
// Create a concrete register for uninitialized locals (Void)
let void_id = crate::mir::builder::emission::constant::emit_void(self);
if std::env::var("NYASH_LOOPFORM_DEBUG").is_ok() {
eprintln!(
"[build_local_statement] '{}': uninitialized, void_id={:?}",
var_name, void_id
crate::mir::builder::control_flow::joinir::trace::trace().stderr_if(
&format!(
"[build_local_statement] '{}': uninitialized, void_id={:?}",
var_name, void_id
),
true,
);
}
void_id
};
if std::env::var("NYASH_LOOPFORM_DEBUG").is_ok() {
eprintln!(
"[build_local_statement] Inserting '{}' -> {:?} into variable_map",
var_name, var_id
crate::mir::builder::control_flow::joinir::trace::trace().stderr_if(
&format!(
"[build_local_statement] Inserting '{}' -> {:?} into variable_map",
var_name, var_id
),
true,
);
}
self.declare_local_in_current_scope(var_name, var_id)?;