{
internal static class CollectCommandHandler
{
- delegate Task<int> CollectDelegate(CancellationToken ct, IConsole console, int processId, string output, bool verbose);
+ delegate Task<int> CollectDelegate(CancellationToken ct, IConsole console, int processId, string output, int timeout, bool verbose);
/// <summary>
/// Collects a gcdump from a currently running process.
/// <param name="processId">The process to collect the gcdump from.</param>
/// <param name="output">The output path for the collected gcdump.</param>
/// <returns></returns>
- private static async Task<int> Collect(CancellationToken ct, IConsole console, int processId, string output, bool verbose)
+ private static async Task<int> Collect(CancellationToken ct, IConsole console, int processId, string output, int timeout, bool verbose)
{
try
{
{
var memoryGraph = new Graphs.MemoryGraph(50_000);
var heapInfo = new DotNetHeapInfo();
- EventPipeDotNetHeapDumper.DumpFromEventPipe(ct, processId, memoryGraph, verbose ? Console.Out : TextWriter.Null, heapInfo);
+ if (!EventPipeDotNetHeapDumper.DumpFromEventPipe(ct, processId, memoryGraph, verbose ? Console.Out : TextWriter.Null, timeout, heapInfo))
+ return false;
memoryGraph.AllowReading();
- GCHeapDump.WriteMemoryGraph(memoryGraph, outputFileInfo.FullName, "dotnet-trace");
+ GCHeapDump.WriteMemoryGraph(memoryGraph, outputFileInfo.FullName, "dotnet-gcdump");
+ return true;
});
- await dumpTask;
+ var fDumpSuccess = await dumpTask;
- outputFileInfo.Refresh();
- Console.Out.WriteLine($"\tFinished writing {outputFileInfo.Length} bytes.");
- return 0;
+ if (fDumpSuccess)
+ {
+ outputFileInfo.Refresh();
+ Console.Out.WriteLine($"\tFinished writing {outputFileInfo.Length} bytes.");
+ return 0;
+ }
+ else if (ct.IsCancellationRequested)
+ {
+ Console.Out.WriteLine($"\tCancelled.");
+ return -1;
+ }
+ else
+ {
+ Console.Out.WriteLine($"\tFailed to collect gcdump. Try running with '-v' for more information.");
+ return -1;
+ }
}
catch (Exception ex)
{
symbols: new Option[] {
ProcessIdOption(),
OutputPathOption(),
- VerboseOption()
+ VerboseOption(),
+ TimeoutOption()
},
handler: HandlerDescriptor.FromDelegate((CollectDelegate)Collect).GetCommandHandler());
description: $"Output the log while collecting the gcdump",
argument: new Argument<bool>(defaultValue: false) { Name = "verbose" },
isHidden: false);
+
+ private static int DefaultTimeout = 30;
+ private static Option TimeoutOption() =>
+ new Option(
+ aliases: new[] { "-t", "--timeout" },
+ description: $"Give up on collecting the gcdump if it takes longer than this many seconds. The default value is {DefaultTimeout}s",
+ argument: new Argument<int>(defaultValue: DefaultTimeout) { Name = "timeout" },
+ isHidden: false);
}
}
using System.Collections.Generic;
using System.Diagnostics;
using System.IO;
-using System.Linq;
-using System.Text;
+using System.Threading;
using System.Threading.Tasks;
namespace Microsoft.Diagnostics.Tools.GCDump
{
public static class EventPipeDotNetHeapDumper
{
+ internal static volatile bool eventPipeDataPresent = false;
+ internal static volatile bool dumpComplete = false;
+
/// <summary>
/// Given a factory for creating an EventPipe session with the appropriate provider and keywords turned on,
/// generate a GCHeapDump using the resulting events. The correct keywords and provider name
/// <param name="log"></param>
/// <param name="dotNetInfo"></param>
/// <returns></returns>
- public static bool DumpFromEventPipe(CancellationToken ct, int processID, MemoryGraph memoryGraph, TextWriter log, DotNetHeapInfo dotNetInfo = null)
+ public static bool DumpFromEventPipe(CancellationToken ct, int processID, MemoryGraph memoryGraph, TextWriter log, int timeout, DotNetHeapInfo dotNetInfo = null)
{
- var sw = Stopwatch.StartNew();
+ var startTicks = Stopwatch.GetTimestamp();
+ Func<TimeSpan> getElapsed = () => TimeSpan.FromTicks(Stopwatch.GetTimestamp() - startTicks);
+
var dumper = new DotNetHeapDumpGraphReader(log)
{
DotNetHeapInfo = dotNetInfo
};
- bool dumpComplete = false;
- bool listening = false;
- EventPipeSession gcDumpSession = null;
- Task readerTask = null;
try
{
- bool eventPipeDataPresent = false;
- TimeSpan lastEventPipeUpdate = sw.Elapsed;
- EventPipeSession typeFlushSession = null;
+ TimeSpan lastEventPipeUpdate = getElapsed();
bool fDone = false;
- var otherListening = false;
- log.WriteLine("{0,5:n1}s: Creating type table flushing task", sw.Elapsed.TotalSeconds);
- var typeTableFlushTask = Task.Factory.StartNew(() =>
+ log.WriteLine("{0,5:n1}s: Creating type table flushing task", getElapsed().TotalSeconds);
+
+ using (EventPipeSession typeFlushSession = new EventPipeSession(processID, new List<Provider> { new Provider("Microsoft-DotNETCore-SampleProfiler") }, false))
{
- typeFlushSession = new EventPipeSession(processID, new List<Provider> { new Provider("Microsoft-DotNETCore-SampleProfiler") }, false);
- otherListening = true;
- log.WriteLine("{0,5:n1}s: Flushing the type table", sw.Elapsed.TotalSeconds);
- typeFlushSession.Source.AllEvents += Task.Run(() =>
- {
+ log.WriteLine("{0,5:n1}s: Flushing the type table", getElapsed().TotalSeconds);
+ typeFlushSession.Source.AllEvents += (traceEvent) => {
if (!fDone)
{
fDone = true;
- typeFlushSession.EndSession();
+ Task.Run(() => typeFlushSession.EndSession())
+ .ContinueWith(_ => typeFlushSession.Source.StopProcessing());
}
- });
+ };
+
typeFlushSession.Source.Process();
- log.WriteLine("{0,5:n1}s: Done flushing the type table", sw.Elapsed.TotalSeconds);
- });
+ log.WriteLine("{0,5:n1}s: Done flushing the type table", getElapsed().TotalSeconds);
+ }
- await typeTableFlushTask;
- // Set up a separate thread that will listen for EventPipe events coming back telling us we succeeded.
- readerTask = Task.Factory.StartNew(delegate
- {
- // Start the providers and trigger the GCs.
- log.WriteLine("{0,5:n1}s: Requesting a .NET Heap Dump", sw.Elapsed.TotalSeconds);
+ // Start the providers and trigger the GCs.
+ log.WriteLine("{0,5:n1}s: Requesting a .NET Heap Dump", getElapsed().TotalSeconds);
- gcDumpSession = new EventPipeSession(processID, new List<Provider> { new Provider("Microsoft-Windows-DotNETRuntime", (ulong)(ClrTraceEventParser.Keywords.GCHeapSnapshot)) });
- int gcNum = -1;
+ using EventPipeSession gcDumpSession = new EventPipeSession(processID, new List<Provider> { new Provider("Microsoft-Windows-DotNETRuntime", (ulong)(ClrTraceEventParser.Keywords.GCHeapSnapshot)) });
+ log.WriteLine("{0,5:n1}s: gcdump EventPipe Session started", getElapsed().TotalSeconds);
- gcDumpSession.Source.Clr.GCStart += delegate (GCStartTraceData data)
+ int gcNum = -1;
+
+ gcDumpSession.Source.Clr.GCStart += delegate (GCStartTraceData data)
+ {
+ if (data.ProcessID != processID)
{
- if (data.ProcessID != processID)
- {
- return;
- }
+ return;
+ }
- eventPipeDataPresent = true;
+ eventPipeDataPresent = true;
- if (gcNum < 0 && data.Depth == 2 && data.Type != GCType.BackgroundGC)
- {
- gcNum = data.Count;
- log.WriteLine("{0,5:n1}s: .NET Dump Started...", sw.Elapsed.TotalSeconds);
- }
- };
-
- gcDumpSession.Source.Clr.GCStop += delegate (GCEndTraceData data)
+ if (gcNum < 0 && data.Depth == 2 && data.Type != GCType.BackgroundGC)
{
- if (data.ProcessID != processID)
- {
- return;
- }
-
- if (data.Count == gcNum)
- {
- log.WriteLine("{0,5:n1}s: .NET GC Complete.", sw.Elapsed.TotalSeconds);
- dumpComplete = true;
- }
- };
+ gcNum = data.Count;
+ log.WriteLine("{0,5:n1}s: .NET Dump Started...", getElapsed().TotalSeconds);
+ }
+ };
- gcDumpSession.Source.Clr.GCBulkNode += delegate (GCBulkNodeTraceData data)
+ gcDumpSession.Source.Clr.GCStop += delegate (GCEndTraceData data)
+ {
+ if (data.ProcessID != processID)
{
- if (data.ProcessID != processID)
- {
- return;
- }
+ return;
+ }
- eventPipeDataPresent = true;
+ if (data.Count == gcNum)
+ {
+ log.WriteLine("{0,5:n1}s: .NET GC Complete.", getElapsed().TotalSeconds);
+ dumpComplete = true;
+ }
+ };
- if ((sw.Elapsed - lastEventPipeUpdate).TotalMilliseconds > 500)
- {
- log.WriteLine("{0,5:n1}s: Making GC Heap Progress...", sw.Elapsed.TotalSeconds);
- }
+ gcDumpSession.Source.Clr.GCBulkNode += delegate (GCBulkNodeTraceData data)
+ {
+ if (data.ProcessID != processID)
+ {
+ return;
+ }
- lastEventPipeUpdate = sw.Elapsed;
- };
+ eventPipeDataPresent = true;
- if (memoryGraph != null)
+ if ((getElapsed() - lastEventPipeUpdate).TotalMilliseconds > 500)
{
- dumper.SetupCallbacks(memoryGraph, gcDumpSession.Source, processID.ToString());
+ log.WriteLine("{0,5:n1}s: Making GC Heap Progress...", getElapsed().TotalSeconds);
}
- listening = true;
- gcDumpSession.Source.Process();
- log.WriteLine("{0,5:n1}s: EventPipe Listener dying", sw.Elapsed.TotalSeconds);
- });
+ lastEventPipeUpdate = getElapsed();
+ };
- // Wait for thread above to start listening (should be very fast)
- while (!listening)
+ if (memoryGraph != null)
{
- readerTask.Wait(1);
+ dumper.SetupCallbacks(memoryGraph, gcDumpSession.Source, processID.ToString());
}
+ // Set up a separate thread that will listen for EventPipe events coming back telling us we succeeded.
+ Task readerTask = Task.Run(() =>
+ {
+ // cancelled before we began
+ if (ct.IsCancellationRequested)
+ return;
+ log.WriteLine("{0,5:n1}s: Starting to process events", getElapsed().TotalSeconds);
+ gcDumpSession.Source.Process();
+ log.WriteLine("{0,5:n1}s: EventPipe Listener dying", getElapsed().TotalSeconds);
+ }, ct);
+
for (; ; )
{
if (ct.IsCancellationRequested)
{
+ log.WriteLine("{0,5:n1}s: Cancelling...", getElapsed().TotalSeconds);
break;
}
break;
}
- if (!eventPipeDataPresent && sw.Elapsed.TotalSeconds > 5) // Assume it started within 5 seconds.
+ if (!eventPipeDataPresent && getElapsed().TotalSeconds > 5) // Assume it started within 5 seconds.
{
- log.WriteLine("{0,5:n1}s: Assume no .NET Heap", sw.Elapsed.TotalSeconds);
+ log.WriteLine("{0,5:n1}s: Assume no .NET Heap", getElapsed().TotalSeconds);
break;
}
- if (sw.Elapsed.TotalSeconds > 30) // Time out after 30 seconds.
+ if (getElapsed().TotalSeconds > timeout) // Time out after `timeout` seconds. defaults to 30s.
{
- log.WriteLine("{0,5:n1}s: Timed out after 20 seconds", sw.Elapsed.TotalSeconds);
+ log.WriteLine("{0,5:n1}s: Timed out after {1} seconds", getElapsed().TotalSeconds, timeout);
break;
}
}
}
- log.WriteLine("{0,5:n1}s: Shutting down EventPipe session", sw.Elapsed.TotalSeconds);
- gcDumpSession.EndSession();
+ var stopTask = Task.Run(() =>
+ {
+ log.WriteLine("{0,5:n1}s: Shutting down gcdump EventPipe session", getElapsed().TotalSeconds);
+ gcDumpSession.EndSession();
+ log.WriteLine("{0,5:n1}s: gcdump EventPipe session shut down", getElapsed().TotalSeconds);
+ }, ct);
+
+ try
+ {
+ while (!Task.WaitAll(new Task[] { readerTask, stopTask }, 1000))
+ log.WriteLine("{0,5:n1}s: still reading...", getElapsed().TotalSeconds);
+ }
+ catch (AggregateException ae) // no need to throw if we're just cancelling the tasks
+ {
+ foreach (var e in ae.Flatten().InnerExceptions)
+ {
+ if (!(e is TaskCanceledException))
+ {
+ throw ae;
+ }
+ }
+ }
+
+ log.WriteLine("{0,5:n1}s: gcdump EventPipe Session closed", getElapsed().TotalSeconds);
- while (!readerTask.Wait(1000))
- log.WriteLine("{0,5:n1}s: still reading...", sw.Elapsed.TotalSeconds);
+ if (ct.IsCancellationRequested)
+ return false;
if (eventPipeDataPresent)
{
}
catch (Exception e)
{
- log.WriteLine($"{sw.Elapsed.TotalSeconds:0,5:n1}s: [Error] Exception during gcdump: {e.ToString()}");
+ log.WriteLine($"{getElapsed().TotalSeconds,5:n1}s: [Error] Exception during gcdump: {e.ToString()}");
}
- log.WriteLine("[{0,5:n1}s: Done Dumping .NET heap success={1}]", sw.Elapsed.TotalSeconds, dumpComplete);
+ log.WriteLine("[{0,5:n1}s: Done Dumping .NET heap success={1}]", getElapsed().TotalSeconds, dumpComplete);
return dumpComplete;
}
}
- internal class EventPipeSession
+ internal class EventPipeSession : IDisposable
{
private List<Provider> _providers;
private Stream _eventPipeStream;
{
EventPipeClient.StopTracing(_pid, _sessionId);
}
+
+ #region IDisposable Support
+ private bool disposedValue = false; // To detect redundant calls
+
+ protected virtual void Dispose(bool disposing)
+ {
+ if (!disposedValue)
+ {
+ if (disposing)
+ {
+ _eventPipeStream?.Dispose();
+ _source?.Dispose();
+ }
+ disposedValue = true;
+ }
+ }
+
+ public void Dispose()
+ {
+ Dispose(true);
+ }
+ #endregion
}
}