425 lines
11 KiB
Nim
425 lines
11 KiB
Nim
## 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()
|