-
Notifications
You must be signed in to change notification settings - Fork 21
Fix MCP trace loading hang #45
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.
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
base: main
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -1,5 +1,6 @@ | ||
| using System; | ||
| using System.ComponentModel; | ||
| using System.Diagnostics; | ||
| using System.IO; | ||
| using System.Linq; | ||
| using System.Threading.Tasks; | ||
|
|
@@ -75,37 +76,69 @@ | |
| throw new InvalidOperationException("MCP action executor is not initialized"); | ||
| } | ||
|
|
||
| Trace.TraceInformation($"[MCP] OpenTrace: file={profileFilePath}, process={processNameOrId}"); | ||
| var stopwatch = System.Diagnostics.Stopwatch.StartNew(); | ||
|
|
||
| // First, check if this might be an ambiguous query by getting available processes | ||
| GetAvailableProcessesResult processesResult = await _executor.GetAvailableProcessesAsync(profileFilePath); | ||
| Trace.TraceInformation($"[MCP] OpenTrace: GetAvailableProcesses completed in {stopwatch.ElapsedMilliseconds}ms, success={processesResult.Success}, count={processesResult.Processes?.Length ?? 0}"); | ||
|
|
||
| if (processesResult.Success) | ||
| { | ||
| // Check if the trace has any profiling data (CPU sampling, PMC, etc.) | ||
| bool hasProfilingData = processesResult.Processes.Any(p => p.WeightPercentage > 0); | ||
|
Check warning on line 89 in src/ProfileExplorer.Mcp/ProfileExplorerMcpServer.cs
|
||
| if (!hasProfilingData) | ||
| { | ||
| Trace.TraceInformation("[MCP] OpenTrace: trace has no profiling samples (no CPU sampling, PMC, or CSwitch data)"); | ||
| var noSamplesResult = new | ||
| { | ||
| Action = "OpenTrace", | ||
| ProfileFilePath = profileFilePath, | ||
| ProcessNameOrId = processNameOrId, | ||
| Status = "Failed", | ||
| FailureReason = "NoProfilingData", | ||
| Description = "The trace file does not contain CPU sampling or performance counter data. It may have been collected without profiling enabled.", | ||
| Timestamp = DateTime.UtcNow | ||
| }; | ||
| return System.Text.Json.JsonSerializer.Serialize(noSamplesResult, new System.Text.Json.JsonSerializerOptions { WriteIndented = true }); | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. We should update SerializeOpenTraceResult for these new errors, or create a new method to handle this. |
||
| } | ||
|
|
||
| // Check for exact matches first (process ID or exact name) | ||
| if (int.TryParse(processNameOrId, out int processId)) | ||
| { | ||
| var exactIdMatch = processesResult.Processes.FirstOrDefault(p => p.ProcessId == processId); | ||
| if (exactIdMatch != null) | ||
| { | ||
| // Direct match by ID - proceed with OpenTrace | ||
| Trace.TraceInformation($"[MCP] OpenTrace: exact ID match found (PID {processId})"); | ||
| OpenTraceResult result = await _executor.OpenTraceAsync(profileFilePath, processNameOrId); | ||
| return SerializeOpenTraceResult(result, profileFilePath, processNameOrId); | ||
| } | ||
| } | ||
|
|
||
| // Check for exact name matches | ||
| var exactNameMatches = processesResult.Processes | ||
| .Where(p => p.Name.Equals(processNameOrId, StringComparison.OrdinalIgnoreCase) || | ||
| (p.ImageFileName?.Equals(processNameOrId, StringComparison.OrdinalIgnoreCase) ?? false)) | ||
| // Check for name matches using bidirectional Contains to handle compound names | ||
| // like "msedgewebview2.exe webview-exe-name=searchhost.exe" matching process "msedgewebview2" | ||
| var nameMatches = processesResult.Processes | ||
| .Where(p => (p.Name != null && ( | ||
| p.Name.Contains(processNameOrId, StringComparison.OrdinalIgnoreCase) || | ||
| processNameOrId.Contains(p.Name, StringComparison.OrdinalIgnoreCase))) || | ||
| (p.ImageFileName != null && ( | ||
| p.ImageFileName.Contains(processNameOrId, StringComparison.OrdinalIgnoreCase) || | ||
| processNameOrId.Contains(p.ImageFileName, StringComparison.OrdinalIgnoreCase)))) | ||
| .ToArray(); | ||
|
|
||
| if (exactNameMatches.Length == 1) | ||
| Trace.TraceInformation($"[MCP] OpenTrace: name matching found {nameMatches.Length} match(es)"); | ||
|
|
||
| if (nameMatches.Length == 1) | ||
| { | ||
| // Single exact match - proceed with OpenTrace | ||
| OpenTraceResult result = await _executor.OpenTraceAsync(profileFilePath, processNameOrId); | ||
| // Single match - proceed with OpenTrace using the matched process ID | ||
| string matchedProcessId = nameMatches[0].ProcessId.ToString(); | ||
| Trace.TraceInformation($"[MCP] OpenTrace: single name match, using PID {matchedProcessId} (name={nameMatches[0].Name})"); | ||
| OpenTraceResult result = await _executor.OpenTraceAsync(profileFilePath, matchedProcessId); | ||
| return SerializeOpenTraceResult(result, profileFilePath, processNameOrId); | ||
| } | ||
|
|
||
| // For ambiguous queries, provide all processes for LLM analysis | ||
| Trace.TraceInformation($"[MCP] OpenTrace: returning RequiresLLMAnalysis ({nameMatches.Length} matches)"); | ||
| var llmAnalysisResult = new | ||
| { | ||
| Action = "OpenTrace", | ||
|
|
@@ -128,9 +161,20 @@ | |
| return System.Text.Json.JsonSerializer.Serialize(llmAnalysisResult, new System.Text.Json.JsonSerializerOptions { WriteIndented = true }); | ||
| } | ||
|
|
||
| // Fallback to direct OpenTrace call if we can't get the process list | ||
| OpenTraceResult directResult = await _executor.OpenTraceAsync(profileFilePath, processNameOrId); | ||
| return SerializeOpenTraceResult(directResult, profileFilePath, processNameOrId); | ||
| // Process list extraction failed - return error instead of falling back to | ||
| // OpenTraceAsync which would open a UI dialog that also can't load processes. | ||
| Trace.TraceInformation($"[MCP] OpenTrace: GetAvailableProcesses failed, returning error (not falling back to UI)"); | ||
| var errorResult2 = new | ||
| { | ||
| Action = "OpenTrace", | ||
| ProfileFilePath = profileFilePath, | ||
| ProcessNameOrId = processNameOrId, | ||
| Status = "Failed", | ||
| FailureReason = "GetAvailableProcessesFailed", | ||
| Description = processesResult.ErrorMessage ?? "Could not extract process list from trace file. The trace may use an unsupported format or be corrupted.", | ||
| Timestamp = DateTime.UtcNow | ||
| }; | ||
| return System.Text.Json.JsonSerializer.Serialize(errorResult2, new System.Text.Json.JsonSerializerOptions { WriteIndented = true }); | ||
|
ivberg marked this conversation as resolved.
|
||
| } | ||
| catch (Exception ex) | ||
| { | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -124,17 +124,29 @@ public List<ProcessSummary> BuildProcessSummary(ProcessListProgressHandler progr | |
| // when it is not set in the trace (-1). | ||
| var kernel = new KernelTraceEventParser(source_, KernelTraceEventParser.ParserTrackingOptions.ThreadToProcess); | ||
|
|
||
| bool traceReopened = false; | ||
|
|
||
| if (!isRealTime_) { | ||
| kernel.EventTraceHeader += data => { | ||
| // If the trace has a known file name it's unlikely | ||
| // to be using a circular buffer which needs the thread -> process ID table, | ||
| // stop reading the entire trace early. | ||
| if (data.LogFileName != "[multiple files]") { | ||
| kernel = ReopenTrace(); | ||
| traceReopened = true; | ||
| } | ||
| }; | ||
|
|
||
| source_.Process(); | ||
|
|
||
| // For merged traces ("[multiple files]"), the first Process() call consumed | ||
| // all events to build the thread→process ID table. Reopen the trace so the | ||
| // second Process() call can re-read events for the actual sample collection. | ||
| DiagnosticLogger.LogInfo($"[BuildProcessSummary] First Process() done, traceReopened={traceReopened}"); | ||
| if (!traceReopened) { | ||
| kernel = ReopenTrace(); | ||
| DiagnosticLogger.LogInfo("[BuildProcessSummary] Reopened trace for merged ETL second pass"); | ||
| } | ||
|
ivberg marked this conversation as resolved.
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. What bug is this one fixing? |
||
| } | ||
|
|
||
| ProfileProcess HandleProcessEvent(ProcessTraceData data) { | ||
|
|
@@ -163,20 +175,24 @@ ProfileProcess HandleProcessEvent(ProcessTraceData data) { | |
| HandleProcessEvent(data); | ||
| }; | ||
|
|
||
| kernel.PerfInfoSample += data => { | ||
| void HandleSampleEvent(int processId, double timeStampRelativeMSec) { | ||
| if (cancelableTask.IsCanceled) { | ||
| source_.StopProcessing(); | ||
| } | ||
|
|
||
| // The thread ID -> process ID mapping is used internally. | ||
| if (data.ProcessID < 0) { | ||
| if (processId < 0) { | ||
| return; | ||
| } | ||
|
|
||
| sampleId++; | ||
| var sampleWeight = TimeSpan.FromMilliseconds(samplingIntervalMS_); | ||
| var sampleTime = TimeSpan.FromMilliseconds(data.TimeStampRelativeMSec); | ||
| summaryBuilder.AddSample(sampleWeight, sampleTime, data.ProcessID); | ||
| var sampleTime = TimeSpan.FromMilliseconds(timeStampRelativeMSec); | ||
| summaryBuilder.AddSample(sampleWeight, sampleTime, processId); | ||
| } | ||
|
|
||
| kernel.PerfInfoSample += data => { | ||
| HandleSampleEvent(data.ProcessID, data.TimeStampRelativeMSec); | ||
|
|
||
| // Rebuild process list and update UI from time to time. | ||
| if (sampleId - lastReportedSample >= SampleReportingInterval) { | ||
|
|
@@ -206,10 +222,55 @@ ProfileProcess HandleProcessEvent(ProcessTraceData data) { | |
| } | ||
| }; | ||
|
|
||
| // Also handle PMC (Performance Monitor Counter) sample events, which are used | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Do we need to flag that the event comes from PMC in the sample event data we are collecting? |
||
| // in traces collected with hardware counter profiling instead of standard CPU sampling. | ||
| kernel.PerfInfoPMCSample += data => { | ||
| HandleSampleEvent(data.ProcessID, data.TimeStampRelativeMSec); | ||
|
|
||
| if (sampleId - lastReportedSample >= SampleReportingInterval) { | ||
| List<ProcessSummary> processList = null; | ||
| var currentTime = DateTime.UtcNow; | ||
|
|
||
| if (sampleId - lastProcessListSample >= nextProcessListSample && | ||
| (currentTime - lastProcessListReport).TotalMilliseconds > 1000) { | ||
| processList = summaryBuilder.MakeSummaries(); | ||
| lastProcessListSample = sampleId; | ||
| lastProcessListReport = currentTime; | ||
| } | ||
|
|
||
| if (progressCallback != null) { | ||
| int current = (int)data.TimeStampRelativeMSec; | ||
| int total = (int)source_.SessionDuration.TotalMilliseconds; | ||
|
|
||
| progressCallback(new ProcessListProgress { | ||
| Total = total, | ||
| Current = current, | ||
| Processes = processList | ||
| }); | ||
| } | ||
|
|
||
| lastReportedSample = sampleId; | ||
| } | ||
| }; | ||
|
|
||
| // Go again over events and accumulate samples to build the process summary. | ||
| DiagnosticLogger.LogInfo("[BuildProcessSummary] Starting second Process() call"); | ||
| source_.Process(); | ||
| var result = summaryBuilder.MakeSummaries(); | ||
| DiagnosticLogger.LogInfo($"[BuildProcessSummary] Second Process() done, sampleId={sampleId}, processes={result?.Count ?? 0}, profileProcesses={profile.Processes?.Count ?? 0}"); | ||
|
|
||
| // For traces without sampling events (e.g., CSwitch/context-switch traces), | ||
| // no samples are collected but processes are discovered via ProcessStart/ProcessEnd. | ||
| // Build summaries from those processes with zero weight so the list isn't empty. | ||
| if (result.Count == 0 && profile.Processes != null && profile.Processes.Count > 0) { | ||
| DiagnosticLogger.LogInfo($"[BuildProcessSummary] No samples found, building process list from {profile.Processes.Count} discovered processes"); | ||
| foreach (var proc in profile.Processes) { | ||
| result.Add(new ProcessSummary(proc, TimeSpan.Zero)); | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. What about having a negative weight? Or null weight? 0 weight could cause some issues if we have some sampled data? |
||
| } | ||
| } | ||
|
|
||
| profile.Dispose(); | ||
| return summaryBuilder.MakeSummaries(); | ||
| return result; | ||
| } | ||
|
|
||
| public RawProfileData ProcessEvents(ProfileLoadProgressHandler progressCallback, | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
call Stop on the stopwatch right before this line