Skip to content

Testing

Jump to bottom
Roger Johansson edited this page Jan 14, 2026 · 2 revisions

Testing

Special testing infrastructure and utilities in Asynkron.JsEngine.

IR Plan Logging

ExecutionPlanPrinter

File: src/Asynkron.JsEngine/Execution/ExecutionPlanPrinter.cs

Pretty-prints IR execution plans for debugging and reasoning about generated IR code.

Printing Complete Plans

var planOutput = ExecutionPlanPrinter.Print(plan.Instructions, plan.EntryPoint);
output.WriteLine(planOutput);

Example Output:

=== Execution Plan (15 instructions, entry: 0) ===

→ [  0] PUSH_ENV (bindings: [i], scopeId: 2, slots: 1, pool: true) → [1]
  [  1] VAR let i = 0 → [2]
  [  2] BRANCH (i < 10) ? [3] : [5]
  [  3] YIELD i → [4]
  [  4] JUMP → [2]
  [  5] POP_ENV (scopeId: 2, pool: true) → [6]
  [  6] RETURN undefined

=== End ===

Format Single Instruction

var formatted = ExecutionPlanPrinter.FormatInstruction(instruction);
// "BRANCH (i < 10) ? [3] : [5]"

Instruction Format Examples

Instruction Format
Jump JUMP → [5]
Branch BRANCH (x < 10) ? [3] : [7]
Variable VAR let i = 0 → [2]
PushEnv PUSH_ENV (bindings: [i, j], scopeId: 2, slots: 2, pool: true) → [1]
PopEnv POP_ENV (scopeId: 2, pool: true) → [6]
Return RETURN value → [8]
Yield YIELD expr → [4]
YieldStar YIELD* iterable (result → x) → [5]
IterInit ITER_INIT expr (slot: $iter, kind: Of) → [2]
IterMoveNext ITER_MOVE_NEXT (iter: $iter, value: item) body: [3], done: [7]
EnterTry ENTER_TRY (handler: [5], finally: [8]) → [1]
BinaryOp BINOP (a + b) → result → [3]
Increment ++i → [2] or i++ → [2]

ExecutionPlanDiagnostics

File: src/Asynkron.JsEngine/Execution/ExecutionPlanDiagnostics.cs

Thread-safe diagnostics for monitoring execution plan building.

Print Plan from Function

var funcDecl = (FunctionDeclaration)program.Body[0];
var planOutput = ExecutionPlanDiagnostics.PrintPlan(funcDecl.Function);

if (planOutput.StartsWith("No execution plan"))
{
    output.WriteLine($"Plan failed: {planOutput}");
}
else
{
    output.WriteLine(planOutput);
}

Track Build Success/Failure

// Reset before test
ExecutionPlanDiagnostics.Reset();

// Execute code
await engine.Evaluate(script);

// Check results
var (attempts, succeeded, failed) = ExecutionPlanDiagnostics.Snapshot();

Assert.True(attempts >= 1);
Assert.True(succeeded >= 1);
Assert.Equal(0, failed);
Assert.Null(ExecutionPlanDiagnostics.LastFailureReason);
Assert.Null(ExecutionPlanDiagnostics.LastFunctionDescription);

Properties

Property Description
LastFailureReason Why the last plan build failed
LastFunctionDescription Which function failed (name or source location)

Execution Tracing

Compile-Time IR Tracing

Enable TRACE_IR_EXECUTION to compile trace methods:

dotnet build -p:DefineConstants=TRACE_IR_EXECUTION

This enables:

  • TraceInstruction() - Log each instruction during execution
  • TraceDefine() - Log variable definitions
  • TraceLookup() - Log variable lookups with resolution status
  • TraceEnvChange() - Log environment push/pop operations

TraceInstruction Output

// Logged during execution:
// [0] PUSH_ENV (bindings: [i], scopeId: 2) [env:A1B2C3D4 scope: 2 d:1]
// [1] VAR let i = 0 [env:A1B2C3D4 scope: 2 d:1]
//   │· DEFINE let 'i' = 0 [env:A1B2C3D4 scope:2]

Runtime DebugMode

await using var engine = new JsEngine(new JsEngineOptions
{
    DebugMode = true,
    Logger = logger
});

Enables:

  • IR trace logging (via Logger)
  • Slot hit/miss logging
  • Pool state logging
  • Additional runtime validation

AST Node Access

AstTestHelpers

File: tests/Asynkron.JsEngine.Tests.Helpers/AstTestHelpers.cs

Utilities for parsing and traversing typed ASTs.

flowchart TB
    subgraph Traversal["AST Traversal"]
        Root((Program)) --> F1((FunctionDecl))
        F1 --> Block((BlockStmt))
        Block --> For((ForStmt))
        For --> Body((Body))
        Body --> If((IfStmt))
    end
    
    subgraph Helpers["AstTestHelpers"]
        FindFirst["FindFirst&lt;T&gt;()"]
        Walk["Walk()"]
        Parse["ParseAndAnalyze()"]
    end
    
    Helpers --> Traversal
Loading

Parse and Analyze

var pipeline = AstTestHelpers.ParseAndAnalyze(@"
    function outer(seed) {
        let baseValue = seed;
        function inner(flag) {
            if (flag) {
                let baseValue = seed + 100;
                return baseValue;
            }
            return baseValue;
        }
        return inner;
    }
");

// Access parsed, analyzed, and CPS-transformed programs
var analyzed = pipeline.Analyzed;

Find Specific Nodes

// Find first node of type
var forStatement = AstTestHelpers.FindFirst<ForStatement>(program);

// Find with predicate
var innerFunc = AstTestHelpers.FindFirst<FunctionExpression>(
    outerFunc.Body,
    f => f.Name?.Name == "inner");

// Find specific node types
var ifStatement = AstTestHelpers.FindFirst<IfStatement>(innerFunc.Body);
var thenBlock = Assert.IsType<BlockStatement>(ifStatement.Then);

Walk All Nodes

// Depth-first traversal
var allFunctions = AstTestHelpers.Walk(program, includeSelf: true)
    .OfType<FunctionDeclaration>()
    .ToList();

var allIdentifiers = AstTestHelpers.Walk(program)
    .OfType<IdentifierExpression>()
    .Where(id => id.Name.Name == "i")
    .ToList();

AST Cache Testing

Access Cached Execution Plans

var funcDecl = (FunctionDeclaration)program.Body[0];
var cache = ((IAstCacheable<ExecutionPlanCache>)funcDecl.Function).GetOrCreateCache();

if (cache.Succeeded)
{
    var plan = cache.Plan!;
    output.WriteLine($"Instructions: {plan.Instructions.Length}");
    output.WriteLine($"Entry: {plan.EntryPoint}");
    output.WriteLine($"FlatSlotCount: {plan.FlatSlotCount}");
    output.WriteLine($"RootScopeId: {plan.RootScopeId}");

    // Inspect specific instructions
    var branches = plan.Instructions.OfType<BranchInstruction>();
    var yields = plan.Instructions.OfType<YieldInstruction>();
}
else
{
    output.WriteLine($"Plan failed: {cache.FailureReason}");
}

Access HoistPlan

var blockStmt = AstTestHelpers.FindFirst<BlockStatement>(program);
var hoistPlan = ((IAstCacheable<HoistPlan>)blockStmt).GetOrCreateCache();

Assert.True(hoistPlan.NeedsEnvironment,
    "Block must allocate lexical environment for let/const");

Access LoopPlan

var forStmt = AstTestHelpers.FindFirst<ForStatement>(program);
var loopPlan = ((IAstCacheable<LoopPlan>)forStmt).GetOrCreateCache();

// Check per-iteration bindings (for closures)
Assert.Equal(["i", "s"], loopPlan.PerIterationBindings.Select(b => b.Name));

Verify Slot Assignments

var cache = ((IAstCacheable<ExecutionPlanCache>)funcDecl.Function).GetOrCreateCache();
var plan = cache.Plan!;

// Find branch instruction and inspect its condition
var branchInstr = plan.Instructions.OfType<BranchInstruction>().First();
var condition = branchInstr.Condition as BinaryExpression;
var leftId = condition.Left as IdentifierExpression;

// Verify identifier has been assigned a slot
Assert.True(leftId.SlotIndex >= 0, "Should have slot index");
Assert.True(leftId.FlatSlotId >= 0, "Should have flat slot ID");
Assert.True(leftId.ScopeId >= 0, "Should have scope ID");

Test Logger

File: tests/Asynkron.JsEngine.Tests.Helpers/TestLogger.cs

Custom ILogger that captures logs for assertion.

Setup

var logger = new TestLogger(
    output,              // xUnit ITestOutputHelper (optional)
    "TestName",          // Logger name
    maxLogCount: 0,      // 0 = unlimited (or set limit for infinite loop detection)
    minLogLevel: LogLevel.Information
);

await using var engine = new JsEngine(new JsEngineOptions
{
    Logger = logger,
    DebugMode = true
});

Inspect Logs

await engine.Evaluate(code);

// Get all captured logs
var records = logger.Collector.Snapshot();

// Check latest log
var latest = logger.Collector.LatestRecord;

// Assert on logs
foreach (var record in records)
{
    output.WriteLine($"[{record.Level}] {record.Message}");
    if (record.Exception is not null)
    {
        output.WriteLine($"  Exception: {record.Exception}");
    }
}

// Search for specific patterns
Assert.Contains(records, r => r.Message.Contains("SlotHit: i"));
Assert.DoesNotContain(records, r => r.Message.Contains("SlotMiss"));

Test Engine Factory

File: tests/Asynkron.JsEngine.Tests.Helpers/TestEngineFactory.cs

Factory for creating pre-configured test engines.

// With explicit logger
var engine = TestEngineFactory.CreateDebugEngine(logger);

// Auto-attach logger if JSENGINE_TRACE_REALM env var is set
var engine = TestEngineFactory.CreateDebugEngine(loggerName: "MyTest");

InternalTestBase

File: tests/Asynkron.JsEngine.Tests/InternalTestBase.cs

Base class with built-in logger support.

public class MyTests : InternalTestBase
{
    public MyTests(ITestOutputHelper output) : base(output) { }

    [Fact]
    public async Task MyTest()
    {
        await using var engine = CreateEngine();  // Has logger + DebugMode

        await engine.Evaluate(code);

        // Access captured logs
        var logs = CurrentLogger?.Collector.Snapshot();
    }
}

Debug Function

Capture execution context at specific points using __debug().

Usage in JavaScript

let x = 42;
let y = 'hello';
__debug();  // Capture state here

Read Debug Messages

await using var engine = CreateDebugEngine();
await engine.Evaluate(source);

var debugMessage = await engine.DebugMessages().ReadAsync();

// Access captured data
var variables = debugMessage.Variables;        // IReadOnlyDictionary<string, object?>
var callStack = debugMessage.CallStack;        // IReadOnlyList<CallStackFrame>
var envChain = debugMessage.EnvironmentChain;  // IReadOnlyList<EnvironmentInfo>

Assert.Equal(42d, variables["x"]);
Assert.Equal("hello", variables["y"]);

EnvironmentInfo

foreach (var env in debugMessage.EnvironmentChain)
{
    output.WriteLine($"ScopeId={env.ScopeId} Slots={env.SlotCount}");

    foreach (var (name, value) in env.DictionaryVariables)
    {
        output.WriteLine($"  {name} = {value}");
    }

    foreach (var (slot, value) in env.SlotVariables)
    {
        output.WriteLine($"  [slot {slot}] = {value}");
    }
}

Compile-Time Debug Features

Define Constants

# Enable IR execution tracing
dotnet build -p:DefineConstants=TRACE_IR_EXECUTION

# Disable object pooling (for baseline debugging)
dotnet build -p:DefineConstants=DISABLE_POOLING

# Disable aggressive inlining (for accurate profiler call stacks)
dotnet build -p:DefineConstants=NO_INLINING

Environment Variables

Variable Effect
JSENGINE_DEBUG_POOL_GUARDS=true Enable runtime pool guards
JSENGINE_TRACE_REALM=true Auto-attach logger in TestEngineFactory

Complete Test Example

[Fact]
public async Task CompleteTestWorkflow()
{
    // 1. Setup with TestLogger
    var logger = new TestLogger(output, "Complete", minLogLevel: LogLevel.Debug);
    await using var engine = new JsEngine(new JsEngineOptions
    {
        Logger = logger,
        DebugMode = true
    });

    // 2. Reset diagnostics
    ExecutionPlanDiagnostics.Reset();

    // 3. Parse and analyze AST
    var program = engine.ParseProgram(@"
        function run() {
            let sum = 0;
            for (let i = 0; i < 10; i++) {
                sum += i;
            }
            return sum;
        }
    ");

    // 4. Find specific AST nodes
    var funcDecl = AstTestHelpers.FindFirst<FunctionDeclaration>(program);
    var forStmt = AstTestHelpers.FindFirst<ForStatement>(funcDecl.Function.Body);

    // 5. Verify AST cache state
    var cache = ((IAstCacheable<ExecutionPlanCache>)funcDecl.Function).GetOrCreateCache();
    Assert.True(cache.Succeeded, $"Plan failed: {cache.FailureReason}");

    // 6. Print IR plan
    var planOutput = ExecutionPlanDiagnostics.PrintPlan(funcDecl.Function);
    output.WriteLine("=== Execution Plan ===");
    output.WriteLine(planOutput);

    // 7. Verify instruction types
    var plan = cache.Plan!;
    Assert.Contains(plan.Instructions, i => i is PushEnvironmentInstruction);
    Assert.Contains(plan.Instructions, i => i is IncrementSlotInstruction);
    Assert.Contains(plan.Instructions, i => i is BranchInstruction);

    // 8. Execute and verify
    await engine.Evaluate(program);
    var result = await engine.Evaluate("run()");
    Assert.Equal(45d, result.AsDouble());

    // 9. Check diagnostics
    var (attempts, succeeded, failed) = ExecutionPlanDiagnostics.Snapshot();
    Assert.Equal(0, failed);

    // 10. Inspect logs
    var logs = logger.Collector.Snapshot();
    output.WriteLine($"Captured {logs.Length} log entries");
}

See Also

Clone this wiki locally