## Dependency Resolver Profiling Tool ## ## This tool profiles the dependency resolver to identify performance ## bottlenecks and hot paths for optimization. ## ## **Profiling Targets:** ## - Variant unification ## - Graph construction ## - Topological sort ## - Conflict detection ## - Cache operations ## ## **Output:** ## - Time spent in each operation ## - Call counts ## - Memory allocations ## - Hot path identification import times import tables import strformat import algorithm type ProfileEntry* = object name*: string totalTime*: float # seconds callCount*: int avgTime*: float # seconds minTime*: float # seconds maxTime*: float # seconds percentage*: float Profiler* = ref object entries*: Table[string, ProfileEntry] startTimes*: Table[string, float] enabled*: bool # ============================================================================ # Global Profiler Instance # ============================================================================ var globalProfiler* = Profiler( entries: initTable[string, ProfileEntry](), startTimes: initTable[string, float](), enabled: false ) # ============================================================================ # Profiling Operations # ============================================================================ proc enable*(profiler: Profiler) = ## Enable profiling profiler.enabled = true profiler.entries.clear() profiler.startTimes.clear() proc disable*(profiler: Profiler) = ## Disable profiling profiler.enabled = false proc isEnabled*(profiler: Profiler): bool = ## Check if profiling is enabled return profiler.enabled proc startProfile*(profiler: Profiler, name: string) = ## Start profiling a code section if not profiler.enabled: return profiler.startTimes[name] = cpuTime() proc endProfile*(profiler: Profiler, name: string) = ## End profiling a code section if not profiler.enabled: return if name notin profiler.startTimes: return let endTime = cpuTime() let startTime = profiler.startTimes[name] let elapsed = endTime - startTime if name in profiler.entries: var entry = profiler.entries[name] entry.totalTime += elapsed entry.callCount += 1 entry.minTime = min(entry.minTime, elapsed) entry.maxTime = max(entry.maxTime, elapsed) entry.avgTime = entry.totalTime / entry.callCount.float profiler.entries[name] = entry else: profiler.entries[name] = ProfileEntry( name: name, totalTime: elapsed, callCount: 1, avgTime: elapsed, minTime: elapsed, maxTime: elapsed, percentage: 0.0 ) profiler.startTimes.del(name) # ============================================================================ # Convenience Macros # ============================================================================ template profile*(profiler: Profiler, name: string, body: untyped) = ## Profile a code block profiler.startProfile(name) try: body finally: profiler.endProfile(name) template profileGlobal*(name: string, body: untyped) = ## Profile a code block using global profiler globalProfiler.startProfile(name) try: body finally: globalProfiler.endProfile(name) # ============================================================================ # Results Analysis # ============================================================================ proc calculatePercentages*(profiler: Profiler) = ## Calculate percentage of total time for each entry var totalTime = 0.0 for entry in profiler.entries.values: totalTime += entry.totalTime if totalTime > 0: for name in profiler.entries.keys: var entry = profiler.entries[name] entry.percentage = (entry.totalTime / totalTime) * 100.0 profiler.entries[name] = entry proc getHotPaths*(profiler: Profiler, topN: int = 10): seq[ProfileEntry] = ## Get top N hot paths by total time result = @[] for entry in profiler.entries.values: result.add(entry) result.sort(proc(a, b: ProfileEntry): int = cmp(b.totalTime, a.totalTime) ) if result.len > topN: result.setLen(topN) proc getFrequentCalls*(profiler: Profiler, topN: int = 10): seq[ProfileEntry] = ## Get top N most frequently called operations result = @[] for entry in profiler.entries.values: result.add(entry) result.sort(proc(a, b: ProfileEntry): int = cmp(b.callCount, a.callCount) ) if result.len > topN: result.setLen(topN) # ============================================================================ # Results Reporting # ============================================================================ proc printReport*(profiler: Profiler) = ## Print profiling report profiler.calculatePercentages() echo "" echo "=" .repeat(90) echo "PROFILING REPORT" echo "=" .repeat(90) echo "" # Summary statistics var totalTime = 0.0 var totalCalls = 0 for entry in profiler.entries.values: totalTime += entry.totalTime totalCalls += entry.callCount echo fmt"Total time: {totalTime * 1000:.2f}ms" echo fmt"Total calls: {totalCalls}" echo fmt"Unique operations: {profiler.entries.len}" echo "" # Hot paths echo "TOP 10 HOT PATHS (by total time):" echo "-" .repeat(90) echo fmt"{'Operation':<40} {'Total':>12} {'Calls':>8} {'Avg':>12} {'%':>6}" echo "-" .repeat(90) let hotPaths = profiler.getHotPaths(10) for entry in hotPaths: echo fmt"{entry.name:<40} {entry.totalTime * 1000:>11.2f}ms {entry.callCount:>8} " & fmt"{entry.avgTime * 1000:>11.2f}ms {entry.percentage:>5.1f}%" echo "" # Frequent calls echo "TOP 10 MOST FREQUENT CALLS:" echo "-" .repeat(90) echo fmt"{'Operation':<40} {'Calls':>8} {'Total':>12} {'Avg':>12} {'%':>6}" echo "-" .repeat(90) let frequentCalls = profiler.getFrequentCalls(10) for entry in frequentCalls: echo fmt"{entry.name:<40} {entry.callCount:>8} {entry.totalTime * 1000:>11.2f}ms " & fmt"{entry.avgTime * 1000:>11.2f}ms {entry.percentage:>5.1f}%" echo "" # Detailed breakdown echo "DETAILED BREAKDOWN:" echo "-" .repeat(90) echo fmt"{'Operation':<40} {'Min':>10} {'Avg':>10} {'Max':>10} {'Calls':>8}" echo "-" .repeat(90) var allEntries: seq[ProfileEntry] = @[] for entry in profiler.entries.values: allEntries.add(entry) allEntries.sort(proc(a, b: ProfileEntry): int = cmp(b.totalTime, a.totalTime) ) for entry in allEntries: echo fmt"{entry.name:<40} {entry.minTime * 1000:>9.2f}ms {entry.avgTime * 1000:>9.2f}ms " & fmt"{entry.maxTime * 1000:>9.2f}ms {entry.callCount:>8}" echo "" proc exportReport*(profiler: Profiler, filename: string) = ## Export profiling report to CSV profiler.calculatePercentages() var csv = "Operation,TotalTime(ms),CallCount,AvgTime(ms),MinTime(ms),MaxTime(ms),Percentage(%)\n" var allEntries: seq[ProfileEntry] = @[] for entry in profiler.entries.values: allEntries.add(entry) allEntries.sort(proc(a, b: ProfileEntry): int = cmp(b.totalTime, a.totalTime) ) for entry in allEntries: csv &= fmt"{entry.name},{entry.totalTime * 1000:.2f},{entry.callCount}," & fmt"{entry.avgTime * 1000:.2f},{entry.minTime * 1000:.2f}," & fmt"{entry.maxTime * 1000:.2f},{entry.percentage:.2f}\n" writeFile(filename, csv) echo fmt"Profile exported to: {filename}" # ============================================================================ # Optimization Recommendations # ============================================================================ proc analyzeAndRecommend*(profiler: Profiler) = ## Analyze profiling data and provide optimization recommendations profiler.calculatePercentages() echo "" echo "=" .repeat(90) echo "OPTIMIZATION RECOMMENDATIONS" echo "=" .repeat(90) echo "" let hotPaths = profiler.getHotPaths(5) for i, entry in hotPaths: echo fmt"{i+1}. {entry.name}" echo fmt" Time: {entry.totalTime * 1000:.2f}ms ({entry.percentage:.1f}% of total)" echo fmt" Calls: {entry.callCount}" echo fmt" Avg: {entry.avgTime * 1000:.2f}ms" echo "" # Provide specific recommendations if entry.percentage > 30.0: echo " ⚠️ CRITICAL: This operation consumes >30% of total time" echo " Recommendations:" echo " - Consider caching results" echo " - Optimize algorithm complexity" echo " - Profile internal operations" elif entry.percentage > 15.0: echo " ⚠️ HIGH PRIORITY: This operation consumes >15% of total time" echo " Recommendations:" echo " - Review algorithm efficiency" echo " - Consider memoization" elif entry.callCount > 1000: echo " ℹ️ HIGH FREQUENCY: Called >1000 times" echo " Recommendations:" echo " - Ensure O(1) or O(log n) complexity" echo " - Consider batching operations" echo "" # ============================================================================ # Example Usage # ============================================================================ when isMainModule: # Enable profiling globalProfiler.enable() # Simulate some operations for i in 0..<100: profileGlobal("variant_unification"): # Simulate work var sum = 0 for j in 0..<1000: sum += j for i in 0..<50: profileGlobal("graph_construction"): # Simulate work var sum = 0 for j in 0..<5000: sum += j for i in 0..<10: profileGlobal("topological_sort"): # Simulate work var sum = 0 for j in 0..<10000: sum += j # Print report globalProfiler.printReport() # Export report globalProfiler.exportReport("/tmp/profile-report.csv") # Analyze and recommend globalProfiler.analyzeAndRecommend()