351 lines
9.7 KiB
Nim
351 lines
9.7 KiB
Nim
## 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()
|