## Tests for Resolver Profiling Infrastructure ## ## This test suite validates the profiling tools and ensures they ## correctly measure and report resolver performance. import unittest import times import os import strformat import strutils import ../src/nip/resolver/profiler suite "Profiler Control": setup: clearProfiler() test "Enable and disable profiler": check not isEnabled() enableProfiler() check isEnabled() disableProfiler() check not isEnabled() test "Clear profiler data": enableProfiler() let opId = startOperation(VariantUnification, "test") sleep(10) endOperation(opId) check globalProfiler.timings.len == 1 clearProfiler() check globalProfiler.timings.len == 0 test "Profiler tracks total time": enableProfiler() sleep(50) disableProfiler() check globalProfiler.totalTime > 0.0 check globalProfiler.totalTime >= 0.05 # At least 50ms suite "Operation Timing": setup: clearProfiler() enableProfiler() teardown: disableProfiler() test "Start and end operation": let opId = startOperation(VariantUnification, "test-op") check opId >= 0 sleep(10) endOperation(opId) check globalProfiler.timings.len == 1 check globalProfiler.timings[0].duration > 0.0 check globalProfiler.timings[0].duration >= 0.01 # At least 10ms test "Multiple operations tracked": let op1 = startOperation(VariantUnification, "op1") sleep(10) endOperation(op1) let op2 = startOperation(GraphConstruction, "op2") sleep(10) endOperation(op2) let op3 = startOperation(ConflictDetection, "op3") sleep(10) endOperation(op3) check globalProfiler.timings.len == 3 check globalProfiler.timings[0].kind == VariantUnification check globalProfiler.timings[1].kind == GraphConstruction check globalProfiler.timings[2].kind == ConflictDetection test "Profile operation template": var executed = false profileOperation(VariantUnification, "template-test"): sleep(10) executed = true check executed check globalProfiler.timings.len == 1 check globalProfiler.timings[0].duration > 0.0 test "Nested operations tracked separately": profileOperation(GraphConstruction, "outer"): sleep(10) profileOperation(VariantUnification, "inner"): sleep(10) check globalProfiler.timings.len == 2 check globalProfiler.timings[0].kind == GraphConstruction check globalProfiler.timings[1].kind == VariantUnification test "Operation timing is accurate": let opId = startOperation(VariantUnification, "timing-test") let startTime = epochTime() sleep(50) # Sleep for 50ms let endTime = epochTime() endOperation(opId) let expectedDuration = endTime - startTime let actualDuration = globalProfiler.timings[0].duration # Allow 10ms tolerance check abs(actualDuration - expectedDuration) < 0.01 suite "Statistics Calculation": setup: clearProfiler() enableProfiler() teardown: disableProfiler() test "Calculate stats for single operation type": for i in 0..<10: profileOperation(VariantUnification, fmt"op-{i}"): sleep(10) disableProfiler() let stats = calculateStats() check stats.len == 1 check stats[0].kind == VariantUnification check stats[0].callCount == 10 check stats[0].totalTime > 0.0 check stats[0].avgTime > 0.0 check stats[0].minTime > 0.0 check stats[0].maxTime > 0.0 test "Calculate stats for multiple operation types": # 10 variant unifications for i in 0..<10: profileOperation(VariantUnification, fmt"unify-{i}"): sleep(5) # 5 graph constructions for i in 0..<5: profileOperation(GraphConstruction, fmt"graph-{i}"): sleep(10) # 3 conflict detections for i in 0..<3: profileOperation(ConflictDetection, fmt"conflict-{i}"): sleep(15) disableProfiler() let stats = calculateStats() check stats.len == 3 # Stats should be sorted by total time (descending) check stats[0].totalTime >= stats[1].totalTime check stats[1].totalTime >= stats[2].totalTime test "Stats calculate percentages correctly": profileOperation(VariantUnification, "op1"): sleep(50) profileOperation(GraphConstruction, "op2"): sleep(50) disableProfiler() let stats = calculateStats() # Both operations should have roughly equal percentages check stats[0].percentOfTotal > 40.0 check stats[0].percentOfTotal < 60.0 check stats[1].percentOfTotal > 40.0 check stats[1].percentOfTotal < 60.0 # Total should be ~100% let totalPercent = stats[0].percentOfTotal + stats[1].percentOfTotal check totalPercent > 95.0 check totalPercent < 105.0 test "Stats track min/max/avg correctly": # Create operations with varying durations profileOperation(VariantUnification, "fast"): sleep(5) profileOperation(VariantUnification, "medium"): sleep(10) profileOperation(VariantUnification, "slow"): sleep(20) disableProfiler() let stats = calculateStats() check stats.len == 1 let s = stats[0] check s.minTime < s.avgTime check s.avgTime < s.maxTime check s.minTime >= 0.005 # At least 5ms check s.maxTime >= 0.020 # At least 20ms suite "Hot Path Identification": setup: clearProfiler() enableProfiler() teardown: disableProfiler() test "Get hot paths returns top operations": # Create operations with different total times for i in 0..<20: profileOperation(VariantUnification, fmt"unify-{i}"): sleep(5) # Total: ~100ms for i in 0..<10: profileOperation(GraphConstruction, fmt"graph-{i}"): sleep(10) # Total: ~100ms for i in 0..<5: profileOperation(ConflictDetection, fmt"conflict-{i}"): sleep(20) # Total: ~100ms disableProfiler() let hotPaths = getHotPaths(3) check hotPaths.len == 3 # All should have similar total times for path in hotPaths: check path.totalTime > 0.0 test "Get hot paths limits results": # Create 5 different operation types for kind in [VariantUnification, GraphConstruction, ConflictDetection, TopologicalSort, SolverExecution]: profileOperation(kind, $kind): sleep(10) disableProfiler() let hotPaths = getHotPaths(3) check hotPaths.len == 3 test "Get hot paths returns all if fewer than limit": profileOperation(VariantUnification, "op1"): sleep(10) profileOperation(GraphConstruction, "op2"): sleep(10) disableProfiler() let hotPaths = getHotPaths(10) check hotPaths.len == 2 suite "Bottleneck Detection": setup: clearProfiler() enableProfiler() teardown: disableProfiler() test "Detect bottlenecks above threshold": # Create one slow operation (>15% of total) profileOperation(VariantUnification, "slow"): sleep(100) # Create many fast operations (<15% of total) for i in 0..<50: profileOperation(GraphConstruction, fmt"fast-{i}"): sleep(1) disableProfiler() let bottlenecks = getBottlenecks(15.0) check bottlenecks.len >= 1 check bottlenecks[0].percentOfTotal >= 15.0 test "No bottlenecks when all operations are balanced": # Create balanced operations for i in 0..<10: profileOperation(VariantUnification, fmt"op-{i}"): sleep(10) disableProfiler() let bottlenecks = getBottlenecks(15.0) check bottlenecks.len == 0 suite "Optimization Recommendations": setup: clearProfiler() enableProfiler() teardown: disableProfiler() test "Recommendations for variant unification bottleneck": profileOperation(VariantUnification, "slow"): sleep(100) for i in 0..<10: profileOperation(GraphConstruction, fmt"fast-{i}"): sleep(1) disableProfiler() let recommendations = getOptimizationRecommendations() check recommendations.len > 0 # Should mention variant unification var foundUnification = false for rec in recommendations: if "variant unification" in rec.toLowerAscii(): foundUnification = true break check foundUnification test "No recommendations when no bottlenecks": # Create balanced operations (each <15% of total) for kind in [VariantUnification, GraphConstruction, ConflictDetection, TopologicalSort, SolverExecution, BuildSynthesis, CacheOperation, HashCalculation]: profileOperation(kind, $kind): sleep(10) disableProfiler() let recommendations = getOptimizationRecommendations() check recommendations.len == 1 check "No major bottlenecks" in recommendations[0] suite "CSV Export": setup: clearProfiler() enableProfiler() teardown: disableProfiler() removeFile("test_profiling.csv") removeFile("test_profiling_detailed.csv") test "Export stats to CSV": profileOperation(VariantUnification, "op1"): sleep(10) profileOperation(GraphConstruction, "op2"): sleep(10) disableProfiler() exportToCSV("test_profiling.csv") check fileExists("test_profiling.csv") let content = readFile("test_profiling.csv") check "Operation,Name,CallCount" in content check "VariantUnification" in content check "GraphConstruction" in content test "Export detailed timings to CSV": profileOperation(VariantUnification, "op1"): sleep(10) profileOperation(GraphConstruction, "op2"): sleep(10) disableProfiler() exportDetailedToCSV("test_profiling_detailed.csv") check fileExists("test_profiling_detailed.csv") let content = readFile("test_profiling_detailed.csv") check "Operation,Name,StartTime,EndTime,Duration" in content check "VariantUnification" in content check "GraphConstruction" in content suite "Report Generation": setup: clearProfiler() enableProfiler() teardown: disableProfiler() test "Print report doesn't crash": profileOperation(VariantUnification, "op1"): sleep(10) profileOperation(GraphConstruction, "op2"): sleep(10) disableProfiler() # Should not crash printReport() test "Print recommendations doesn't crash": profileOperation(VariantUnification, "op1"): sleep(100) for i in 0..<10: profileOperation(GraphConstruction, fmt"fast-{i}"): sleep(1) disableProfiler() # Should not crash printOptimizationRecommendations()