Skip to content

Add extensive pipeline logging for long-running stages #12

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
elbruno merged 1 commit into from
Jul 1, 2026
Merged

Add extensive pipeline logging for long-running stages #12

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
50 changes: 41 additions & 9 deletions src/Graphify.Cli/PipelineRunner.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
using System.Collections.Concurrent;
using System.Diagnostics;
using Graphify.Export;
using Graphify.Graph;
using Graphify.Models;
Expand Down Expand Up @@ -33,12 +34,15 @@ public PipelineRunner(TextWriter output, bool verbose = false, IChatClient? chat
{
try
{
var pipelineStopwatch = Stopwatch.StartNew();
await WriteLineAsync("graphify-dotnet: Transform codebases into knowledge graphs");
await WriteLineAsync(new string('─', 60));
await WriteLineAsync($"Started at: {DateTimeOffset.Now:HH:mm:ss}");
await WriteLineAsync();

// Stage 1: Detect files
await WriteLineAsync("[1/6] Detecting files...");
var detectStopwatch = Stopwatch.StartNew();
var fileDetector = new FileDetector();
var detectorOptions = new FileDetectorOptions(
RootPath: inputPath,
Expand All @@ -48,6 +52,7 @@ public PipelineRunner(TextWriter output, bool verbose = false, IChatClient? chat

var detectedFiles = await fileDetector.ExecuteAsync(detectorOptions, cancellationToken);
await WriteLineAsync($" Found {detectedFiles.Count} files to process");
await WriteLineAsync($" Detection completed in {FormatElapsed(detectStopwatch.Elapsed)}");
if (_verbose)
{
foreach (var file in detectedFiles.Take(5))
Expand All @@ -68,6 +73,7 @@ public PipelineRunner(TextWriter output, bool verbose = false, IChatClient? chat
int processed = 0;
int skipped = 0;
int completed = 0;
var extractionStopwatch = Stopwatch.StartNew();
var verboseWarnings = new ConcurrentQueue<string>();
var extractionProgressStep = Math.Max(1, detectedFiles.Count / 10);

Expand Down Expand Up @@ -124,19 +130,22 @@ await Parallel.ForEachAsync(
var totalNodes = extractionResults.Sum(r => r.Nodes.Count);
var totalEdges = extractionResults.Sum(r => r.Edges.Count);
await WriteLineAsync($" Extracted {totalNodes} nodes, {totalEdges} edges");
await WriteLineAsync($" Extraction completed in {FormatElapsed(extractionStopwatch.Elapsed)}");
await WriteLineAsync();

// Stage 2b: AI-enhanced semantic extraction (if provider configured)
if (_chatClient != null)
{
await WriteLineAsync("[2b/6] Running AI-enhanced semantic extraction...");
var semanticStopwatch = Stopwatch.StartNew();
var semanticExtractor = new SemanticExtractor(_chatClient);
int semanticProcessed = 0;
int semanticCompleted = 0;
var semanticProgressStep = Math.Max(1, detectedFiles.Count / 10);

foreach (var file in detectedFiles)
for (var index = 0; index < detectedFiles.Count; index++)
{
var file = detectedFiles[index];
cancellationToken.ThrowIfCancellationRequested();
try
{
Expand Down Expand Up @@ -164,6 +173,7 @@ await Parallel.ForEachAsync(
totalNodes = extractionResults.Sum(r => r.Nodes.Count);
totalEdges = extractionResults.Sum(r => r.Edges.Count);
await WriteLineAsync($" Total: {totalNodes} nodes, {totalEdges} edges (AST + AI)");
await WriteLineAsync($" Semantic extraction completed in {FormatElapsed(semanticStopwatch.Elapsed)}");
await WriteLineAsync();
}
else
Expand All @@ -175,6 +185,7 @@ await Parallel.ForEachAsync(

// Stage 3: Build graph
await WriteLineAsync("[3/6] Building knowledge graph...");
var graphBuildStopwatch = Stopwatch.StartNew();
var graphBuilder = new GraphBuilder(new GraphBuilderOptions
{
CreateFileNodes = true,
Expand All @@ -183,10 +194,12 @@ await Parallel.ForEachAsync(
});
var graph = await graphBuilder.ExecuteAsync(extractionResults, cancellationToken);
await WriteLineAsync($" Graph: {graph.NodeCount} nodes, {graph.EdgeCount} edges");
await WriteLineAsync($" Graph build completed in {FormatElapsed(graphBuildStopwatch.Elapsed)}");
await WriteLineAsync();

// Stage 4: Detect communities (clustering)
await WriteLineAsync("[4/6] Detecting communities...");
var clusterStopwatch = Stopwatch.StartNew();
var clusterEngine = new ClusterEngine(new ClusterOptions
{
MaxIterations = 100,
Expand All @@ -201,10 +214,12 @@ await Parallel.ForEachAsync(
.Distinct()
.Count();
await WriteLineAsync($" Found {communityCount} communities");
await WriteLineAsync($" Clustering completed in {FormatElapsed(clusterStopwatch.Elapsed)}");
await WriteLineAsync();

// Stage 5: Analyze graph
await WriteLineAsync("[5/6] Analyzing graph structure...");
var analysisStopwatch = Stopwatch.StartNew();
var analyzer = new Analyzer(new AnalyzerOptions
{
TopGodNodesCount = 10,
Expand All @@ -215,6 +230,7 @@ await Parallel.ForEachAsync(
await WriteLineAsync($" God nodes: {analysis.GodNodes.Count}");
await WriteLineAsync($" Surprising connections: {analysis.SurprisingConnections.Count}");
await WriteLineAsync($" Suggested questions: {analysis.SuggestedQuestions.Count}");
await WriteLineAsync($" Analysis completed in {FormatElapsed(analysisStopwatch.Elapsed)}");
await WriteLineAsync();

// Prepare community labels and cohesion scores for report and exports
Expand All @@ -223,6 +239,7 @@ await Parallel.ForEachAsync(

// Stage 6: Export
await WriteLineAsync("[6/6] Exporting results...");
var exportStopwatch = Stopwatch.StartNew();

// Validate output directory to prevent path traversal
var validator = new Graphify.Security.InputValidator();
Expand All @@ -238,6 +255,7 @@ await Parallel.ForEachAsync(
{
try
{
var formatStopwatch = Stopwatch.StartNew();
var normalizedFormat = format.ToLowerInvariant();

switch (normalizedFormat)
Expand All @@ -246,49 +264,49 @@ await Parallel.ForEachAsync(
var jsonExporter = new JsonExporter();
var jsonPath = Path.Combine(outputDir, "graph.json");
await jsonExporter.ExportAsync(graph, jsonPath, cancellationToken);
await WriteLineAsync($" Exported JSON: {jsonPath}");
await WriteLineAsync($" Exported JSON: {jsonPath}{FormatWithElapsed(formatStopwatch.Elapsed)}");
break;

case "html":
var htmlExporter = new HtmlExporter();
var htmlPath = Path.Combine(outputDir, "graph.html");
await htmlExporter.ExportAsync(graph, htmlPath, communityLabels, cancellationToken);
await WriteLineAsync($" Exported HTML: {htmlPath}");
await WriteLineAsync($" Exported HTML: {htmlPath}{FormatWithElapsed(formatStopwatch.Elapsed)}");
break;

case "svg":
var svgExporter = new SvgExporter();
var svgPath = Path.Combine(outputDir, "graph.svg");
await svgExporter.ExportAsync(graph, svgPath, cancellationToken);
await WriteLineAsync($" Exported SVG: {svgPath}");
await WriteLineAsync($" Exported SVG: {svgPath}{FormatWithElapsed(formatStopwatch.Elapsed)}");
break;

case "neo4j":
var neo4jExporter = new Neo4jExporter();
var cypherPath = Path.Combine(outputDir, "graph.cypher");
await neo4jExporter.ExportAsync(graph, cypherPath, cancellationToken);
await WriteLineAsync($" Exported Neo4j Cypher: {cypherPath}");
await WriteLineAsync($" Exported Neo4j Cypher: {cypherPath}{FormatWithElapsed(formatStopwatch.Elapsed)}");
break;

case "ladybug":
var ladybugExporter = new LadybugExporter();
var ladybugPath = Path.Combine(outputDir, "graph.ladybug.cypher");
await ladybugExporter.ExportAsync(graph, ladybugPath, cancellationToken);
await WriteLineAsync($" Exported Ladybug Cypher: {ladybugPath}");
await WriteLineAsync($" Exported Ladybug Cypher: {ladybugPath}{FormatWithElapsed(formatStopwatch.Elapsed)}");
break;

case "obsidian":
var obsidianExporter = new ObsidianExporter();
var obsidianPath = Path.Combine(outputDir, "obsidian");
await obsidianExporter.ExportAsync(graph, obsidianPath, cancellationToken);
await WriteLineAsync($" Exported Obsidian vault: {obsidianPath}/");
await WriteLineAsync($" Exported Obsidian vault: {obsidianPath}/{FormatWithElapsed(formatStopwatch.Elapsed)}");
break;

case "wiki":
var wikiExporter = new WikiExporter();
var wikiPath = Path.Combine(outputDir, "wiki");
await wikiExporter.ExportAsync(graph, wikiPath, cancellationToken);
await WriteLineAsync($" Exported Wiki: {wikiPath}/");
await WriteLineAsync($" Exported Wiki: {wikiPath}/{FormatWithElapsed(formatStopwatch.Elapsed)}");
break;

case "report":
Expand All @@ -297,7 +315,7 @@ await Parallel.ForEachAsync(
var reportMarkdown = reportGenerator.Generate(graph, analysis, communityLabels, cohesionScores, projectName);
var reportPath = Path.Combine(outputDir, "GRAPH_REPORT.md");
await File.WriteAllTextAsync(reportPath, reportMarkdown, cancellationToken);
await WriteLineAsync($" Exported Report: {reportPath}");
await WriteLineAsync($" Exported Report: {reportPath}{FormatWithElapsed(formatStopwatch.Elapsed)}");
break;

default:
Expand All @@ -310,9 +328,11 @@ await Parallel.ForEachAsync(
await WriteLineAsync($" Error exporting {format}: {ex.Message}");
}
}
await WriteLineAsync($" Export stage completed in {FormatElapsed(exportStopwatch.Elapsed)}");

await WriteLineAsync();
await WriteLineAsync("✓ Pipeline completed successfully");
await WriteLineAsync($"Total runtime: {FormatElapsed(pipelineStopwatch.Elapsed)}");
await WriteLineAsync();

// Print summary
Expand Down Expand Up @@ -371,6 +391,18 @@ private static bool ShouldReportProgress(int completed, int total, int step)
return completed == total || completed % step == 0;
}

private static string FormatElapsed(TimeSpan elapsed)
{
return elapsed.TotalSeconds >= 1
? $"{elapsed.TotalSeconds:F2}s"
: $"{elapsed.TotalMilliseconds:F0}ms";
}

private string FormatWithElapsed(TimeSpan elapsed)
{
return _verbose ? $" ({FormatElapsed(elapsed)})" : string.Empty;
}

private static Dictionary<int, string> BuildCommunityLabels(KnowledgeGraph graph)
{
var result = new Dictionary<int, string>();
Expand Down
50 changes: 48 additions & 2 deletions src/Graphify/Pipeline/WatchMode.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
using System.Collections.Concurrent;
using System.Diagnostics;
using Graphify.Cache;
using Graphify.Export;
using Graphify.Graph;
Expand Down Expand Up @@ -127,6 +128,7 @@ private async Task ProcessChangesAsync(

try
{
var updateStopwatch = Stopwatch.StartNew();
// Filter to files that actually changed content (via SHA256)
var trulyChanged = new List<string>();
foreach (var filePath in changedPaths)
Expand All @@ -148,6 +150,11 @@ private async Task ProcessChangesAsync(
}
}

if (_verbose)
{
await _output.WriteLineAsync($" Scanned {changedPaths.Count} path(s) in {FormatElapsed(updateStopwatch.Elapsed)}");
}

if (trulyChanged.Count == 0)
{
if (_verbose)
Expand All @@ -173,7 +180,12 @@ private async Task ProcessChangesAsync(
MaxFileSizeBytes: 1024 * 1024,
RespectGitIgnore: true);

var detectStopwatch = Stopwatch.StartNew();
var allDetected = await fileDetector.ExecuteAsync(options, ct);
if (_verbose)
{
await _output.WriteLineAsync($" Re-detected {allDetected.Count} file(s) in {FormatElapsed(detectStopwatch.Elapsed)}");
}

// Filter to changed files only
var changedSet = new HashSet<string>(trulyChanged, StringComparer.OrdinalIgnoreCase);
Expand All @@ -190,14 +202,19 @@ private async Task ProcessChangesAsync(
var newResults = new List<ExtractionResult>();
var progressStep = Math.Max(1, filesToProcess.Count / 10);
var completed = 0;
var extractStopwatch = Stopwatch.StartNew();
var extracted = 0;
foreach (var file in filesToProcess)
{
ct.ThrowIfCancellationRequested();
try
{
var result = await extractor.ExecuteAsync(file, ct);
if (result.Nodes.Count > 0 || result.Edges.Count > 0)
{
newResults.Add(result);
extracted++;
}
}
catch (Exception ex)
{
Expand All @@ -206,9 +223,10 @@ private async Task ProcessChangesAsync(
}

completed++;
if (completed == filesToProcess.Count || completed % progressStep == 0)
if (ShouldReportProgress(completed, filesToProcess.Count, progressStep))
{
await _output.WriteLineAsync($" Progress: {completed}/{filesToProcess.Count} changed files analyzed");
await _output.WriteLineAsync(
$" Progress: {completed}/{filesToProcess.Count} changed files analyzed ({extracted} produced output, {FormatElapsed(extractStopwatch.Elapsed)})");
}
}

Expand All @@ -226,10 +244,16 @@ private async Task ProcessChangesAsync(
MergeStrategy = MergeStrategy.MostRecent
});

var buildStopwatch = Stopwatch.StartNew();
var incrementalGraph = await graphBuilder.ExecuteAsync(newResults, ct);
_currentGraph!.MergeGraph(incrementalGraph);
if (_verbose)
{
await _output.WriteLineAsync($" Graph merge completed in {FormatElapsed(buildStopwatch.Elapsed)}");
}

// Re-cluster
var clusterStopwatch = Stopwatch.StartNew();
var clusterEngine = new ClusterEngine(new ClusterOptions
{
MaxIterations = 100,
Expand All @@ -238,8 +262,13 @@ private async Task ProcessChangesAsync(
MaxCommunityFraction = 0.2
});
_currentGraph = await clusterEngine.ExecuteAsync(_currentGraph, ct);
if (_verbose)
{
await _output.WriteLineAsync($" Re-clustering completed in {FormatElapsed(clusterStopwatch.Elapsed)}");
}

// Re-export
var exportStopwatch = Stopwatch.StartNew();
Directory.CreateDirectory(outputDir);
foreach (var format in formats)
{
Expand All @@ -254,9 +283,14 @@ private async Task ProcessChangesAsync(
break;
}
}
if (_verbose)
{
await _output.WriteLineAsync($" Export completed in {FormatElapsed(exportStopwatch.Elapsed)}");
}

await _output.WriteLineAsync($" Re-processed {newResults.Count} file(s) → {_currentGraph.NodeCount} nodes, {_currentGraph.EdgeCount} edges");
await _output.WriteLineAsync($" Exported to {outputDir}");
await _output.WriteLineAsync($" Incremental update total time: {FormatElapsed(updateStopwatch.Elapsed)}");
await _output.WriteLineAsync();
}
catch (OperationCanceledException)
Expand All @@ -281,4 +315,16 @@ public void Dispose()
_watcher.Dispose();
_processLock.Dispose();
}

private static string FormatElapsed(TimeSpan elapsed)
{
return elapsed.TotalSeconds >= 1
? $"{elapsed.TotalSeconds:F2}s"
: $"{elapsed.TotalMilliseconds:F0}ms";
}

private static bool ShouldReportProgress(int completed, int total, int step)
{
return completed == total || completed % step == 0;
}
}
Loading