public static async Task <bool> TEST_TracesHaveRelevantEvents()
{
bool fSuccess = true;
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
var server = new ReverseServer(serverName);
using var memoryStream = new MemoryStream();
Task <bool> subprocessTask = Utils.RunSubprocess(
currentAssembly: Assembly.GetExecutingAssembly(),
environment: new Dictionary <string, string> {
{ Utils.DiagnosticPortsEnvKey, $"{serverName}" }
},
duringExecution: async(pid) =>
{
Stream stream = await server.AcceptAsync();
IpcAdvertise advertise = IpcAdvertise.Parse(stream);
Logger.logger.Log(advertise.ToString());
var config = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-Windows-DotNETRuntimePrivate", 0x80000000, EventLevel.Verbose)
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream eventStream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
Task readerTask = eventStream.CopyToAsync(memoryStream);
Logger.logger.Log($"Send ResumeRuntime Diagnostics IPC Command");
// send ResumeRuntime command (0x04=ProcessCommandSet, 0x01=ResumeRuntime commandid)
var message = new IpcMessage(0x04, 0x01);
Logger.logger.Log($"Sent: {message.ToString()}");
IpcMessage response = IpcClient.SendMessage(stream, message);
Logger.logger.Log($"received: {response.ToString()}");
await Task.Delay(TimeSpan.FromSeconds(2));
Logger.logger.Log("Stopping EventPipeSession over standard connection");
EventPipeClient.StopTracing(pid, sessionId);
await readerTask;
Logger.logger.Log("Stopped EventPipeSession over standard connection");
}
);
fSuccess &= await subprocessTask;
memoryStream.Seek(0, SeekOrigin.Begin);
using var source = new EventPipeEventSource(memoryStream);
var parser = new ClrPrivateTraceEventParser(source);
bool isStartupEventPresent = false;
parser.StartupEEStartupStart += (eventData) => isStartupEventPresent = true;
source.Process();
Logger.logger.Log($"isStartupEventPresent: {isStartupEventPresent}");
return(isStartupEventPresent && fSuccess);
}
public void V4EventPipeFileHasProcNumbers()
{
PrepareTestData();
const string eventPipeFileName = "eventpipe-dotnetcore3.0-win-x64-objver4.nettrace";
string eventPipeFilePath = Path.Combine(UnZippedDataDir, eventPipeFileName);
using (var traceSource = new EventPipeEventSource(eventPipeFilePath))
{
Assert.Equal(4, traceSource.NumberOfProcessors);
int[] counts = new int[4];
Action <TraceEvent> handler = delegate(TraceEvent data)
{
Assert.True(data.ProcessorNumber >= 0 && data.ProcessorNumber < traceSource.NumberOfProcessors);
counts[data.ProcessorNumber]++;
};
var privateClr = new ClrPrivateTraceEventParser(traceSource);
privateClr.All += handler;
traceSource.Clr.All += handler;
traceSource.Clr.MethodILToNativeMap -= handler;
traceSource.Dynamic.All += handler;
// Process
traceSource.Process();
for (int i = 0; i < traceSource.NumberOfProcessors; i++)
{
Assert.NotEqual(0, counts[i]);
}
}
}
public bool LoadEvents(int procID, int sampleInterval100ns)
{
m_procID = procID;
m_SampleInterval = sampleInterval100ns / 10000.0;
// Filter to process
TraceEvents processEvents = m_traceLog.Events.Filter(FilterEvent);
// Get Dispatcher
TraceEventDispatcher source = processEvents.GetSource();
kernelGuid = KernelTraceEventParser.ProviderGuid;
// Hookup events
source.Clr.All += OnClrEvent;
ClrPrivateTraceEventParser clrPrivate = new ClrPrivateTraceEventParser(source);
clrPrivate.All += OnClrPrivateEvent;
KernelTraceEventParser kernel = source.Kernel;
kernel.PerfInfoSample += delegate(SampledProfileTraceData data)
{
ThreadMemoryInfo thread = GetThread(data.ThreadID);
thread.AddEvent(HeapEvents.CPUSample, data.TimeStampRelativeMSec);
};
kernel.VirtualMemAlloc += OnVirtualMem;
kernel.VirtualMemFree += OnVirtualMem;
m_processLookup = new Dictionary <int, Microsoft.Diagnostics.Tracing.Analysis.TraceProcess>();
// Process all events into GCProcess lookup dictionary
Microsoft.Diagnostics.Tracing.Analysis.TraceLoadedDotNetRuntimeExtensions.NeedLoadedDotNetRuntimes(source);
Microsoft.Diagnostics.Tracing.Analysis.TraceProcessesExtensions.AddCallbackOnProcessStart(source, proc =>
{
Microsoft.Diagnostics.Tracing.Analysis.TraceProcessesExtensions.SetSampleIntervalMSec(proc, sampleInterval100ns);
proc.Log = m_traceLog;
});
source.Process();
foreach (var proc in Microsoft.Diagnostics.Tracing.Analysis.TraceProcessesExtensions.Processes(source))
{
if (Microsoft.Diagnostics.Tracing.Analysis.TraceLoadedDotNetRuntimeExtensions.LoadedDotNetRuntime(proc) != null)
{
m_processLookup.Add(proc.ProcessID, proc);
}
}
// Get the process we want
if (!m_processLookup.ContainsKey(procID))
{
return(false);
}
m_process = m_processLookup[procID];
m_runtime = Microsoft.Diagnostics.Tracing.Analysis.TraceLoadedDotNetRuntimeExtensions.LoadedDotNetRuntime(m_process);
return(true);
}
public PinningStackAnalysis(TraceEventDispatcher source, TraceProcess process, MutableTraceEventStackSource stackSource, TextWriter log)
: base(source, process, stackSource, log)
{
var clrPrivateParser = new ClrPrivateTraceEventParser(source);
clrPrivateParser.GCSetGCHandle += OnSetGCHandle;
source.Clr.GCSetGCHandle += OnSetGCHandle;
AllocateObject = () => new PinningStackAnalysisObject();
}
public bool LoadEvents(int procID, int sampleInterval100ns)
{
m_procID = procID;
m_SampleInterval = sampleInterval100ns / 10000.0;
// Filter to process
TraceEvents processEvents = m_traceLog.Events.Filter(FilterEvent);
// Get Dispatcher
TraceEventDispatcher source = processEvents.GetSource();
kernelGuid = KernelTraceEventParser.ProviderGuid;
// Hookup events
source.Clr.All += OnClrEvent;
ClrPrivateTraceEventParser clrPrivate = new ClrPrivateTraceEventParser(source);
clrPrivate.All += OnClrPrivateEvent;
KernelTraceEventParser kernel = source.Kernel;
kernel.PerfInfoSample += delegate(SampledProfileTraceData data)
{
ThreadMemoryInfo thread = GetThread(data.ThreadID);
thread.AddEvent(HeapEvents.CPUSample, data.TimeStampRelativeMSec);
};
kernel.VirtualMemAlloc += OnVirtualMem;
kernel.VirtualMemFree += OnVirtualMem;
m_processLookup = new ProcessLookup <GCProcess>();
// Process all events into GCProcess lookup dictionary
GCProcess.Collect(source, sampleInterval100ns, m_processLookup, null, false, m_traceLog);
// Get the process we want
return(m_processLookup.TryGetByID(procID, out m_gcProcess));
}
public static async Task <bool> TEST_MultipleConnectPortsSuspend()
{
bool fSuccess = true;
var serverAndNames = new List <(ReverseServer, string)>();
string dotnetDiagnosticPorts = "";
for (int i = 0; i < s_NumberOfPorts; i++)
{
string serverName = ReverseServer.MakeServerAddress();
var server = new ReverseServer(serverName);
Logger.logger.Log($"Server {i} address is '{serverName}'");
serverAndNames.Add((server, serverName));
dotnetDiagnosticPorts += $"{serverName};";
}
Logger.logger.Log($"export DOTNET_DiagnosticPorts={dotnetDiagnosticPorts}");
var advertisements = new List <IpcAdvertise>();
Object sync = new Object();
int subprocessId = -1;
Task <bool> subprocessTask = Utils.RunSubprocess(
currentAssembly: Assembly.GetExecutingAssembly(),
environment: new Dictionary <string, string>
{
{ Utils.DiagnosticPortsEnvKey, dotnetDiagnosticPorts }
},
duringExecution: async(int pid) =>
{
subprocessId = pid;
// Create an eventpipe session that will tell us when
// the EEStartupStarted event happens. This will tell us
// the the runtime has been resumed. This should only happen
// AFTER all suspend ports have sent the resume command.
var config = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-Windows-DotNETRuntimePrivate", 0x80000000, EventLevel.Verbose),
// workaround for https://github.com/dotnet/runtime/issues/44072 which happens because the
// above provider only sends 2 events and that can cause EventPipeEventSource (from TraceEvent)
// to not dispatch the events if the EventBlock is a size not divisible by 8 (the reading alignment in TraceEvent).
// Adding this provider keeps data flowing over the pipe so the reader doesn't get stuck waiting for data
// that won't come otherwise.
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream eventStream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
var mre = new ManualResetEvent(false);
Task readerTask = Task.Run(async() =>
{
Logger.logger.Log($"Creating EventPipeEventSource");
using var source = new EventPipeEventSource(eventStream);
var parser = new ClrPrivateTraceEventParser(source);
parser.StartupEEStartupStart += (eventData) => mre.Set();
Logger.logger.Log($"Created EventPipeEventSource");
Logger.logger.Log($"Starting processing");
await Task.Run(() => source.Process());
Logger.logger.Log($"Finished processing");
});
for (int i = 0; i < s_NumberOfPorts; i++)
{
fSuccess &= !mre.WaitOne(0);
Logger.logger.Log($"Runtime HAS NOT resumed (expects: true): {fSuccess}");
var(server, _) = serverAndNames[i];
int serverIndex = i;
Stream stream = await server.AcceptAsync();
IpcAdvertise advertise = IpcAdvertise.Parse(stream);
lock (sync)
advertisements.Add(advertise);
Logger.logger.Log($"Server {serverIndex} got advertise {advertise.ToString()}");
// send resume command on this connection
var message = new IpcMessage(0x04, 0x01);
Logger.logger.Log($"Port {serverIndex} sent: {message.ToString()}");
IpcMessage response = IpcClient.SendMessage(stream, message);
Logger.logger.Log($"Port {serverIndex} received: {response.ToString()}");
}
Logger.logger.Log($"Waiting on EEStartupStarted event");
mre.WaitOne();
Logger.logger.Log($"Saw EEStartupStarted Event");
Logger.logger.Log($"Stopping EventPipeSession");
EventPipeClient.StopTracing(pid, sessionId);
await readerTask;
Logger.logger.Log($"Stopped EventPipeSession");
// runtime should have resumed now
fSuccess &= mre.WaitOne(0);
Logger.logger.Log($"Runtime HAS resumed (expects: true): {fSuccess}");
}
);
fSuccess &= await subprocessTask;
foreach (var(server, _) in serverAndNames)
{
server.Shutdown();
}
if (advertisements.Count() > 0)
{
Guid referenceCookie = advertisements[0].RuntimeInstanceCookie;
foreach (var adv in advertisements)
{
fSuccess &= (int)adv.ProcessId == subprocessId;
fSuccess &= adv.RuntimeInstanceCookie.Equals(referenceCookie);
}
}
else
{
fSuccess &= false;
}
return(fSuccess);
}
public static async Task <bool> TEST_SuspendDefaultPort()
{
bool fSuccess = true;
int subprocessId = -1;
Task <bool> subprocessTask = Utils.RunSubprocess(
currentAssembly: Assembly.GetExecutingAssembly(),
environment: new Dictionary <string, string>
{
{ Utils.DiagnosticPortSuspend, "1" }
},
duringExecution: async(int pid) =>
{
subprocessId = pid;
// Create an eventpipe session that will tell us when
// the EEStartupStarted event happens. This will tell us
// the the runtime has been resumed. This should only happen
// AFTER all suspend ports have sent the resume command.
var config = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-Windows-DotNETRuntimePrivate", 0x80000000, EventLevel.Verbose),
// workaround for https://github.com/dotnet/runtime/issues/44072 which happens because the
// above provider only sends 2 events and that can cause EventPipeEventSource (from TraceEvent)
// to not dispatch the events if the EventBlock is a size not divisible by 8 (the reading alignment in TraceEvent).
// Adding this provider keeps data flowing over the pipe so the reader doesn't get stuck waiting for data
// that won't come otherwise.
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream eventStream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
var mre = new ManualResetEvent(false);
Task readerTask = Task.Run(async() =>
{
Logger.logger.Log($"Creating EventPipeEventSource");
using var source = new EventPipeEventSource(eventStream);
var parser = new ClrPrivateTraceEventParser(source);
parser.StartupEEStartupStart += (eventData) => mre.Set();
Logger.logger.Log($"Created EventPipeEventSource");
Logger.logger.Log($"Starting processing");
await Task.Run(() => source.Process());
Logger.logger.Log($"Finished processing");
});
fSuccess &= !mre.WaitOne(0);
Logger.logger.Log($"Runtime HAS NOT resumed (expects: true): {fSuccess}");
// send resume command on this connection
var message = new IpcMessage(0x04, 0x01);
Logger.logger.Log($"Sent: {message.ToString()}");
IpcMessage response = IpcClient.SendMessage(ConnectionHelper.GetStandardTransport(pid), message);
Logger.logger.Log($"Received: {response.ToString()}");
Logger.logger.Log($"Waiting for EEStartupStarted event");
mre.WaitOne();
Logger.logger.Log($"Saw EEStartupStarted event!");
Logger.logger.Log($"Stopping EventPipeSession");
EventPipeClient.StopTracing(pid, sessionId);
await readerTask;
Logger.logger.Log($"Stopped EventPipeSession");
// runtime should have resumed now
fSuccess &= mre.WaitOne(0);
Logger.logger.Log($"Runtime HAS resumed (expects: true): {fSuccess}");
}
);
fSuccess &= await subprocessTask;
return(fSuccess);
}
public IEnumerable <Counter> Parse(string mergeTraceFile, string processName, IList <int> pids)
{
var results = new List <double>();
double threadTime = 0;
var threadTimes = new List <double>();
var ins = new Dictionary <int, double>();
double start = -1;
int? pid = null;
using (var source = new ETWTraceEventSource(mergeTraceFile))
{
source.Kernel.ProcessStart += evt =>
{
if (evt.ProcessName.Equals(processName, StringComparison.OrdinalIgnoreCase) && pids.Contains(evt.ProcessID))
{
if (pid.HasValue)
{
// Processes might be reentrant. For now this traces the first (outermost) process of a given name.
return;
}
pid = evt.ProcessID;
start = evt.TimeStampRelativeMSec;
}
};
source.Kernel.ThreadCSwitch += evt =>
{
if (!pid.HasValue) // we're currently in a measurement interval
{
return;
}
if (evt.NewProcessID != pid && evt.OldProcessID != pid)
{
return; // but this isn't our process
}
if (evt.OldProcessID == pid) // this is a switch out from our process
{
if (ins.TryGetValue(evt.OldThreadID, out var value)) // had we ever recorded a switch in for this thread?
{
threadTime += evt.TimeStampRelativeMSec - value;
ins.Remove(evt.OldThreadID);
}
}
else // this is a switch in to our process
{
ins[evt.NewThreadID] = evt.TimeStampRelativeMSec;
}
};
ClrPrivateTraceEventParser clrpriv = new ClrPrivateTraceEventParser(source);
clrpriv.StartupMainStart += evt =>
{
if (pid.HasValue && evt.ProcessID == pid && evt.ProcessName.Equals(processName, StringComparison.OrdinalIgnoreCase))
{
results.Add(evt.TimeStampRelativeMSec - start);
pid = null;
threadTimes.Add(threadTime);
threadTime = 0;
start = 0;
}
};
source.Process();
}
return(new[] { new Counter()
{
Name = "Time To Main", Results = results.ToArray(), TopCounter = true, DefaultCounter = true, HigherIsBetter = false, MetricName = "ms"
},
new Counter()
{
Name = "Time on Thread", Results = threadTimes.ToArray(), TopCounter = true, DefaultCounter = false, HigherIsBetter = false, MetricName = "ms"
} });
}
public void Streaming(string eventPipeFileName)
{
// Initialize
PrepareTestData();
string eventPipeFilePath = Path.Combine(UnZippedDataDir, eventPipeFileName);
Output.WriteLine(string.Format("Processing the file {0}", Path.GetFullPath(eventPipeFilePath)));
var eventStatistics = new SortedDictionary <string, EventRecord>(StringComparer.Ordinal);
long curStreamPosition = 0;
using (MockStreamingOnlyStream s = new MockStreamingOnlyStream(new FileStream(eventPipeFilePath, FileMode.Open, FileAccess.Read, FileShare.Read)))
{
using (var traceSource = new EventPipeEventSource(s))
{
Action <TraceEvent> handler = delegate(TraceEvent data)
{
long newStreamPosition = s.TestOnlyPosition;
// Empirically these files have event blocks of no more than 103K bytes each
// The streaming code should never need to read ahead beyond the end of the current
// block to read the events
Assert.InRange(newStreamPosition, curStreamPosition, curStreamPosition + 103_000);
curStreamPosition = newStreamPosition;
string eventName = data.ProviderName + "/" + data.EventName;
// For whatever reason the parse filtering below produces a couple extra events
// that TraceLog managed to filter out:
// Microsoft-Windows-DotNETRuntime/Method, 2,
// Microsoft-Windows-DotNETRuntimeRundown/Method, 26103, ...
// I haven't had an oportunity to investigate and its probably not a big
// deal so just hacking around it for the moment
if (eventName == "Microsoft-Windows-DotNETRuntimeRundown/Method" ||
eventName == "Microsoft-Windows-DotNETRuntime/Method")
{
return;
}
if (eventStatistics.ContainsKey(eventName))
{
eventStatistics[eventName].TotalCount++;
}
else
{
eventStatistics[eventName] = new EventRecord()
{
TotalCount = 1,
FirstSeriazliedSample = new String(data.ToString().Replace("\n", "\\n").Replace("\r", "\\r").Take(1000).ToArray())
};
}
};
// this is somewhat arbitrary looking set of parser event callbacks empirically
// produces the same set of events as TraceLog.Events.GetSource().AllEvents so
// that the baseline files can be reused from the Basic test
var rundown = new ClrRundownTraceEventParser(traceSource);
rundown.LoaderAppDomainDCStop += handler;
rundown.LoaderAssemblyDCStop += handler;
rundown.LoaderDomainModuleDCStop += handler;
rundown.LoaderModuleDCStop += handler;
rundown.MethodDCStopComplete += handler;
rundown.MethodDCStopInit += handler;
var sampleProfiler = new SampleProfilerTraceEventParser(traceSource);
sampleProfiler.All += handler;
var privateClr = new ClrPrivateTraceEventParser(traceSource);
privateClr.All += handler;
traceSource.Clr.All += handler;
traceSource.Clr.MethodILToNativeMap -= handler;
traceSource.Dynamic.All += handler;
// Process
traceSource.Process();
}
}
// Validate
ValidateEventStatistics(eventStatistics, eventPipeFileName);
}
public IEnumerable <Counter> Parse(string mergeTraceFile, string processName, IList <int> pids, string commandLine)
{
var results = new List <double>();
double threadTime = 0;
var threadTimes = new List <double>();
var ins = new Dictionary <int, double>();
double start = -1;
int? pid = null;
using (var source = new TraceSourceManager(mergeTraceFile))
{
source.Kernel.ProcessStart += evt =>
{
if (!pid.HasValue && ParserUtility.MatchProcessStart(evt, source, processName, pids, commandLine))
{
pid = evt.ProcessID;
start = evt.TimeStampRelativeMSec;
}
};
if (source.IsWindows)
{
((ETWTraceEventSource)source.Source).Kernel.ThreadCSwitch += evt =>
{
if (!pid.HasValue) // we're currently in a measurement interval
{
return;
}
if (evt.NewProcessID != pid && evt.OldProcessID != pid)
{
return; // but this isn't our process
}
if (evt.OldProcessID == pid) // this is a switch out from our process
{
if (ins.TryGetValue(evt.OldThreadID, out var value)) // had we ever recorded a switch in for this thread?
{
threadTime += evt.TimeStampRelativeMSec - value;
ins.Remove(evt.OldThreadID);
}
}
else // this is a switch in to our process
{
ins[evt.NewThreadID] = evt.TimeStampRelativeMSec;
}
};
}
ClrPrivateTraceEventParser clrpriv = new ClrPrivateTraceEventParser(source.Source);
clrpriv.StartupMainStart += evt =>
{
if (pid.HasValue && ParserUtility.MatchSingleProcessID(evt, source, (int)pid))
{
results.Add(evt.TimeStampRelativeMSec - start);
pid = null;
start = 0;
if (source.IsWindows)
{
threadTimes.Add(threadTime);
threadTime = 0;
}
}
};
source.Process();
}
var ret = new List <Counter> {
new Counter()
{
Name = "Time To Main", Results = results.ToArray(), TopCounter = true, DefaultCounter = true, HigherIsBetter = false, MetricName = "ms"
}
};
if (threadTimes.Count != 0)
{
ret.Add(new Counter()
{
Name = "Time on Thread", Results = threadTimes.ToArray(), TopCounter = true, DefaultCounter = false, HigherIsBetter = false, MetricName = "ms"
});
}
return(ret);
}
public static async Task <bool> TEST_ProcessInfoBeforeAndAfterSuspension()
{
// This test only applies to platforms where the PAL is used
if (RuntimeInformation.IsOSPlatform(OSPlatform.Windows))
{
return(true);
}
// This test only applies to CoreCLR (this checks if we're running on Mono)
if (Type.GetType("Mono.RuntimeStructs") != null)
{
return(true);
}
bool fSuccess = true;
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
var server = new ReverseServer(serverName);
using var memoryStream1 = new MemoryStream();
using var memoryStream2 = new MemoryStream();
using var memoryStream3 = new MemoryStream();
Task <bool> subprocessTask = Utils.RunSubprocess(
currentAssembly: Assembly.GetExecutingAssembly(),
environment: new Dictionary <string, string> {
{ Utils.DiagnosticPortsEnvKey, $"{serverName}" }
},
duringExecution: async(pid) =>
{
Process currentProcess = Process.GetCurrentProcess();
Stream stream = await server.AcceptAsync();
IpcAdvertise advertise = IpcAdvertise.Parse(stream);
Logger.logger.Log(advertise.ToString());
Logger.logger.Log($"Get ProcessInfo while process is suspended");
// 0x04 = ProcessCommandSet, 0x04 = ProcessInfo2
var message = new IpcMessage(0x04, 0x04);
Logger.logger.Log($"Sent: {message.ToString()}");
IpcMessage response = IpcClient.SendMessage(stream, message);
Logger.logger.Log($"received: {response.ToString()}");
ProcessInfo2 pi2Before = ProcessInfo2.TryParse(response.Payload);
Utils.Assert(pi2Before.Commandline.Equals(currentProcess.MainModule.FileName), $"Before resuming, the commandline should be the mock value of the host executable path '{currentProcess.MainModule.FileName}'. Observed: '{pi2Before.Commandline}'");
// recycle
stream = await server.AcceptAsync();
advertise = IpcAdvertise.Parse(stream);
Logger.logger.Log(advertise.ToString());
// Start EP session to know when runtime is resumed
var config = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-Windows-DotNETRuntimePrivate", 0x80000000, EventLevel.Verbose),
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream eventStream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
TaskCompletionSource <bool> runtimeResumed = new(false, TaskCreationOptions.RunContinuationsAsynchronously);
var eventPipeTask = Task.Run(() =>
{
Logger.logger.Log("Creating source");
using var source = new EventPipeEventSource(eventStream);
var parser = new ClrPrivateTraceEventParser(source);
parser.StartupEEStartupStart += (_) => runtimeResumed.SetResult(true);
source.Process();
Logger.logger.Log("stopping processing");
});
Logger.logger.Log($"Send ResumeRuntime Diagnostics IPC Command");
// send ResumeRuntime command (0x04=ProcessCommandSet, 0x01=ResumeRuntime commandid)
message = new IpcMessage(0x04, 0x01);
Logger.logger.Log($"Sent: {message.ToString()}");
response = IpcClient.SendMessage(stream, message);
Logger.logger.Log($"received: {response.ToString()}");
// recycle
stream = await server.AcceptAsync();
advertise = IpcAdvertise.Parse(stream);
Logger.logger.Log(advertise.ToString());
// wait a little bit to make sure the runtime of the target is fully up, i.e., g_EEStarted == true
// on resource constrained CI machines this may not be instantaneous
Logger.logger.Log($"awaiting resume");
await Utils.WaitTillTimeout(runtimeResumed.Task, TimeSpan.FromSeconds(10));
Logger.logger.Log($"resumed");
// await Task.Delay(TimeSpan.FromSeconds(1));
Logger.logger.Log("Stopping EventPipeSession over standard connection");
EventPipeClient.StopTracing(pid, sessionId);
Logger.logger.Log($"Await reader task");
await eventPipeTask;
Logger.logger.Log("Stopped EventPipeSession over standard connection");
ProcessInfo2 pi2After = default;
// The timing is not exact. There is a small window after resuming where the mock
// value is still present. Retry several times to catch it.
var retryTask = Task.Run(async() =>
{
int i = 0;
do
{
Logger.logger.Log($"Get ProcessInfo after resumption: attempt {i++}");
// 0x04 = ProcessCommandSet, 0x04 = ProcessInfo2
message = new IpcMessage(0x04, 0x04);
Logger.logger.Log($"Sent: {message.ToString()}");
response = IpcClient.SendMessage(stream, message);
Logger.logger.Log($"received: {response.ToString()}");
pi2After = ProcessInfo2.TryParse(response.Payload);
// recycle
stream = await server.AcceptAsync();
advertise = IpcAdvertise.Parse(stream);
Logger.logger.Log(advertise.ToString());
} while (pi2After.Commandline.Equals(pi2Before.Commandline));
});
await Utils.WaitTillTimeout(retryTask, TimeSpan.FromSeconds(10));
Utils.Assert(!pi2After.Commandline.Equals(pi2Before.Commandline), $"After resuming, the commandline should be the correct value. Observed: Before='{pi2Before.Commandline}' After='{pi2After.Commandline}'");
}
);
fSuccess &= await subprocessTask;
return(fSuccess);
}
public static async Task <bool> TEST_MultipleSessionsCanBeStartedWhilepaused()
{
bool fSuccess = true;
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
var server = new ReverseServer(serverName);
using var memoryStream1 = new MemoryStream();
using var memoryStream2 = new MemoryStream();
using var memoryStream3 = new MemoryStream();
Task <bool> subprocessTask = Utils.RunSubprocess(
currentAssembly: Assembly.GetExecutingAssembly(),
environment: new Dictionary <string, string> {
{ Utils.DiagnosticsMonitorAddressEnvKey, serverName }
},
duringExecution: async(pid) =>
{
Stream stream = await server.AcceptAsync();
IpcAdvertise advertise = IpcAdvertise.Parse(stream);
Logger.logger.Log(advertise.ToString());
var config = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-Windows-DotNETRuntimePrivate", 0x80000000, EventLevel.Verbose)
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream eventStream1 = EventPipeClient.CollectTracing(pid, config, out var sessionId1);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId1:x}");
Task readerTask1 = eventStream1.CopyToAsync(memoryStream1);
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream eventStream2 = EventPipeClient.CollectTracing(pid, config, out var sessionId2);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId2:x}");
Task readerTask2 = eventStream2.CopyToAsync(memoryStream2);
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream eventStream3 = EventPipeClient.CollectTracing(pid, config, out var sessionId3);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId3:x}");
Task readerTask3 = eventStream3.CopyToAsync(memoryStream3);
Logger.logger.Log($"Send ResumeRuntime Diagnostics IPC Command");
// send ResumeRuntime command (0xFF=ServerCommandSet, 0x01=ResumeRuntime commandid)
var message = new IpcMessage(0xFF, 0x01);
Logger.logger.Log($"Sent: {message.ToString()}");
IpcMessage response = IpcClient.SendMessage(stream, message);
Logger.logger.Log($"received: {response.ToString()}");
await Task.Delay(TimeSpan.FromSeconds(2));
Logger.logger.Log("Stopping EventPipeSession over standard connection");
EventPipeClient.StopTracing(pid, sessionId1);
EventPipeClient.StopTracing(pid, sessionId2);
EventPipeClient.StopTracing(pid, sessionId3);
await readerTask1;
await readerTask2;
await readerTask3;
Logger.logger.Log("Stopped EventPipeSession over standard connection");
}
);
fSuccess &= await Utils.WaitTillTimeout(subprocessTask, TimeSpan.FromMinutes(1));
int nStartupEventsSeen = 0;
memoryStream1.Seek(0, SeekOrigin.Begin);
using (var source = new EventPipeEventSource(memoryStream1))
{
var parser = new ClrPrivateTraceEventParser(source);
parser.StartupEEStartupStart += (eventData) => nStartupEventsSeen++;
source.Process();
}
memoryStream2.Seek(0, SeekOrigin.Begin);
using (var source = new EventPipeEventSource(memoryStream2))
{
var parser = new ClrPrivateTraceEventParser(source);
parser.StartupEEStartupStart += (eventData) => nStartupEventsSeen++;
source.Process();
}
memoryStream3.Seek(0, SeekOrigin.Begin);
using (var source = new EventPipeEventSource(memoryStream3))
{
var parser = new ClrPrivateTraceEventParser(source);
parser.StartupEEStartupStart += (eventData) => nStartupEventsSeen++;
source.Process();
}
Logger.logger.Log($"nStartupEventsSeen: {nStartupEventsSeen}");
return(nStartupEventsSeen == 3 && fSuccess);
}
internal static IDictionary<int, GCProcess> Collect(
TraceEventSource source,
float sampleIntervalMSec,
IDictionary<int, GCProcess> perProc = null,
MutableTraceEventStackSource stackSource = null,
Predicate<TraceEvent> filterFunc = null)
{
if (perProc == null)
{
perProc = new Dictionary<int, GCProcess>();
}
source.Kernel.AddCallbackForEvents(delegate (ProcessCtrTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
var stats = perProc.GetOrCreate(data.ProcessID);
stats.PeakVirtualMB = ((double)data.PeakVirtualSize) / 1000000.0;
stats.PeakWorkingSetMB = ((double)data.PeakWorkingSetSize) / 1000000.0;
});
Action<RuntimeInformationTraceData> doAtRuntimeStart = delegate (RuntimeInformationTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
var stats = perProc.GetOrCreate(data.ProcessID);
stats.RuntimeVersion = "V " + data.VMMajorVersion.ToString() + "." + data.VMMinorVersion + "." + data.VMBuildNumber
+ "." + data.VMQfeNumber;
stats.StartupFlags = data.StartupFlags;
stats.Bitness = (data.RuntimeDllPath.ToLower().Contains("framework64") ? 64 : 32);
if (stats.CommandLine == null)
stats.CommandLine = data.CommandLine;
};
// log at both startup and rundown
//var clrRundown = new ClrRundownTraceEventParser(source);
//clrRundown.RuntimeStart += doAtRuntimeStart;
source.Clr.AddCallbackForEvent("Runtime/Start", doAtRuntimeStart);
Action<ProcessTraceData> processStartCallback = data =>
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
var stats = perProc.GetOrCreate(data.ProcessID);
if (!string.IsNullOrEmpty(data.KernelImageFileName))
{
// When we just have an EventSource (eg, the source was created by
// ETWTraceEventSource), we don't necessarily have the process names
// decoded - it all depends on whether we have seen a ProcessStartGroup
// event or not. When the trace was taken after the process started we
// know we didn't see such an event.
string name = GetImageName(data.KernelImageFileName);
// Strictly speaking, this is not really fixing it 'cause
// it doesn't handle when a process with the same name starts
// with the same pid. The chance of that happening is really small.
if (stats.isDead == true)
{
stats = new GCProcess();
stats.Init(data);
perProc[data.ProcessID] = stats;
}
}
var commandLine = data.CommandLine;
if (!string.IsNullOrEmpty(commandLine))
stats.CommandLine = commandLine;
};
source.Kernel.AddCallbackForEvent("Process/Start", processStartCallback);
source.Kernel.AddCallbackForEvent("Process/DCStart", processStartCallback);
Action<ProcessTraceData> processEndCallback = delegate (ProcessTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
var stats = perProc.GetOrCreate(data.ProcessID);
if (string.IsNullOrEmpty(stats.ProcessName))
{
stats.ProcessName = GetImageName(data.KernelImageFileName);
}
if (data.OpcodeName == "Stop")
{
stats.isDead = true;
}
};
source.Kernel.AddCallbackForEvent("Process/Stop", processEndCallback);
source.Kernel.AddCallbackForEvent("Process/DCStop", processEndCallback);
#if (!CAP)
CircularBuffer<ThreadWorkSpan> RecentThreadSwitches = new CircularBuffer<ThreadWorkSpan>(10000);
source.Kernel.AddCallbackForEvent("Thread/CSwitch", delegate (CSwitchTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
RecentThreadSwitches.Add(new ThreadWorkSpan(data));
GCProcess stats;
if (perProc.TryGetValue(data.ProcessID, out stats))
{
stats.ThreadId2Priority[data.NewThreadID] = data.NewThreadPriority;
if (stats.IsServerGCThread(data.ThreadID) > -1)
{
stats.ServerGcHeap2ThreadId[data.ProcessorNumber] = data.ThreadID;
}
}
foreach (var gcProcess in perProc.Values)
{
GCEvent _event = gcProcess.GetCurrentGC();
// If we are in the middle of a GC.
if (_event != null)
{
if ((_event.Type != GCType.BackgroundGC) && (gcProcess.isServerGCUsed == 1))
{
_event.AddServerGcThreadSwitch(new ThreadWorkSpan(data));
}
}
}
});
CircularBuffer<ThreadWorkSpan> RecentCpuSamples = new CircularBuffer<ThreadWorkSpan>(1000);
StackSourceSample sample = new StackSourceSample(stackSource);
source.Kernel.AddCallbackForEvent("PerfInfo/Sample", delegate (SampledProfileTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
RecentCpuSamples.Add(new ThreadWorkSpan(data));
GCProcess processWithGc = null;
foreach (var gcProcess in perProc.Values)
{
GCEvent e = gcProcess.GetCurrentGC();
// If we are in the middle of a GC.
if (e != null)
{
if ((e.Type != GCType.BackgroundGC) && (gcProcess.isServerGCUsed == 1))
{
e.AddServerGcSample(new ThreadWorkSpan(data));
processWithGc = gcProcess;
}
}
}
if (stackSource != null && processWithGc != null)
{
GCEvent e = processWithGc.GetCurrentGC();
sample.Metric = 1;
sample.TimeRelativeMSec = data.TimeStampRelativeMSec;
var nodeName = string.Format("Server GCs #{0} in {1} (PID:{2})", e.GCNumber, processWithGc.ProcessName, processWithGc.ProcessID);
var nodeIndex = stackSource.Interner.FrameIntern(nodeName);
sample.StackIndex = stackSource.Interner.CallStackIntern(nodeIndex, stackSource.GetCallStack(data.CallStackIndex(), data));
stackSource.AddSample(sample);
}
GCProcess stats;
if (perProc.TryGetValue(data.ProcessID, out stats))
{
if (stats.IsServerGCThread(data.ThreadID) > -1)
{
stats.ServerGcHeap2ThreadId[data.ProcessorNumber] = data.ThreadID;
}
var cpuIncrement = sampleIntervalMSec;
stats.ProcessCpuMSec += cpuIncrement;
GCEvent _event = stats.GetCurrentGC();
// If we are in the middle of a GC.
if (_event != null)
{
bool isThreadDoingGC = false;
if ((_event.Type != GCType.BackgroundGC) && (stats.isServerGCUsed == 1))
{
int heapIndex = stats.IsServerGCThread(data.ThreadID);
if (heapIndex != -1)
{
_event.AddServerGCThreadTime(heapIndex, cpuIncrement);
isThreadDoingGC = true;
}
}
else if (data.ThreadID == stats.suspendThreadIDGC)
{
_event.GCCpuMSec += cpuIncrement;
isThreadDoingGC = true;
}
else if (stats.IsBGCThread(data.ThreadID))
{
Debug.Assert(stats.currentBGC != null);
if (stats.currentBGC != null)
stats.currentBGC.GCCpuMSec += cpuIncrement;
isThreadDoingGC = true;
}
if (isThreadDoingGC)
{
stats.GCCpuMSec += cpuIncrement;
}
}
}
});
#endif
source.Clr.AddCallbackForEvent("GC/SuspendEEStart", delegate (GCSuspendEETraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
var stats = perProc.GetOrCreate(data.ProcessID);
switch (data.Reason)
{
case GCSuspendEEReason.SuspendForGC:
stats.suspendThreadIDGC = data.ThreadID;
break;
case GCSuspendEEReason.SuspendForGCPrep:
stats.suspendThreadIDBGC = data.ThreadID;
break;
default:
stats.suspendThreadIDOther = data.ThreadID;
break;
}
stats.suspendTimeRelativeMSec = data.TimeStampRelativeMSec;
});
// In 2.0 we didn't have this event.
source.Clr.AddCallbackForEvent("GC/SuspendEEStop", delegate (GCNoUserDataTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
if ((stats.suspendThreadIDBGC > 0) && (stats.currentBGC != null))
{
stats.currentBGC._SuspendDurationMSec += data.TimeStampRelativeMSec - stats.suspendTimeRelativeMSec;
}
stats.suspendEndTimeRelativeMSec = data.TimeStampRelativeMSec;
});
source.Clr.AddCallbackForEvent("GC/RestartEEStop", delegate (GCNoUserDataTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
GCEvent _event = stats.GetCurrentGC();
if (_event != null)
{
if (_event.Type == GCType.BackgroundGC)
{
stats.AddConcurrentPauseTime(_event, data.TimeStampRelativeMSec);
}
else
{
Debug.Assert(_event.PauseStartRelativeMSec != 0);
// In 2.0 Concurrent GC, since we don't know the GC's type we can't tell if it's concurrent
// or not. But we know we don't have nested GCs there so simply check if we have received the
// GCStop event; if we have it means it's a blocking GC; otherwise it's a concurrent GC so
// simply add the pause time to the GC without making the GC complete.
if (_event.GCDurationMSec == 0)
{
Debug.Assert(_event.is20Event);
_event.isConcurrentGC = true;
stats.AddConcurrentPauseTime(_event, data.TimeStampRelativeMSec);
}
else
{
_event.PauseDurationMSec = data.TimeStampRelativeMSec - _event.PauseStartRelativeMSec;
if (_event.HeapStats != null)
{
_event.isComplete = true;
stats.lastCompletedGC = _event;
}
}
}
}
// We don't change between a GC end and the pause resume.
//Debug.Assert(stats.allocTickAtLastGC == stats.allocTickCurrentMB);
// Mark that we are not in suspension anymore.
stats.suspendTimeRelativeMSec = -1;
stats.suspendThreadIDOther = -1;
stats.suspendThreadIDBGC = -1;
stats.suspendThreadIDGC = -1;
});
source.Clr.AddCallbackForEvent("GC/AllocationTick", delegate (GCAllocationTickTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
if (stats.HasAllocTickEvents == false)
{
stats.HasAllocTickEvents = true;
}
double valueMB = data.GetAllocAmount(ref stats.SeenBadAllocTick) / 1000000.0;
if (data.AllocationKind == GCAllocationKind.Small)
{
// Would this do the right thing or is it always 0 for SOH since AllocationAmount
// is an int???
stats.allocTickCurrentMB[0] += valueMB;
}
else
{
stats.allocTickCurrentMB[1] += valueMB;
}
});
source.Clr.AddCallbackForEvent("GC/Start", delegate (GCStartTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
// We need to filter the scenario where we get 2 GCStart events for each GC.
if ((stats.suspendThreadIDGC > 0) &&
!((stats.events.Count > 0) && stats.events[stats.events.Count - 1].GCNumber == data.Count))
{
GCEvent _event = new GCEvent(stats);
Debug.Assert(0 <= data.Depth && data.Depth <= 2);
// _event.GCGeneration = data.Depth; Old style events only have this in the GCStop event.
_event.Reason = data.Reason;
_event.GCNumber = data.Count;
_event.Type = data.Type;
_event.Index = stats.events.Count;
_event.is20Event = data.IsClassicProvider;
bool isEphemeralGCAtBGCStart = false;
// Detecting the ephemeral GC that happens at the beginning of a BGC.
if (stats.events.Count > 0)
{
GCEvent lastGCEvent = stats.events[stats.events.Count - 1];
if ((lastGCEvent.Type == GCType.BackgroundGC) &&
(!lastGCEvent.isComplete) &&
(data.Type == GCType.NonConcurrentGC))
{
isEphemeralGCAtBGCStart = true;
}
}
Debug.Assert(stats.suspendTimeRelativeMSec != -1);
if (isEphemeralGCAtBGCStart)
{
_event.PauseStartRelativeMSec = data.TimeStampRelativeMSec;
}
else
{
_event.PauseStartRelativeMSec = stats.suspendTimeRelativeMSec;
if (stats.suspendEndTimeRelativeMSec == -1)
{
stats.suspendEndTimeRelativeMSec = data.TimeStampRelativeMSec;
}
_event._SuspendDurationMSec = stats.suspendEndTimeRelativeMSec - stats.suspendTimeRelativeMSec;
}
_event.GCStartRelativeMSec = data.TimeStampRelativeMSec;
stats.events.Add(_event);
if (_event.Type == GCType.BackgroundGC)
{
stats.currentBGC = _event;
_event.ProcessCpuAtLastGC = stats.ProcessCpuAtLastGC;
}
#if (!CAP)
if ((_event.Type != GCType.BackgroundGC) && (stats.isServerGCUsed == 1))
{
_event.SetUpServerGcHistory();
foreach (var s in RecentCpuSamples)
_event.AddServerGcSample(s);
foreach (var s in RecentThreadSwitches)
_event.AddServerGcThreadSwitch(s);
}
#endif
}
});
source.Clr.AddCallbackForEvent("GC/PinObjectAtGCTime", delegate (PinObjectAtGCTimeTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
GCEvent _event = stats.GetCurrentGC();
if (_event != null)
{
if (!_event.PinnedObjects.ContainsKey(data.ObjectID))
{
_event.PinnedObjects.Add(data.ObjectID, data.ObjectSize);
}
else
{
_event.duplicatedPinningReports++;
}
}
});
// Some builds have this as a public event, and some have it as a private event.
// All will move to the private event, so we'll remove this code afterwards.
source.Clr.AddCallbackForEvent("GC/PinPlugAtGCTime", delegate (PinPlugAtGCTimeTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
GCEvent _event = stats.GetCurrentGC();
if (_event != null)
{
// ObjectID is supposed to be an IntPtr. But "Address" is defined as UInt64 in
// TraceEvent.
_event.PinnedPlugs.Add(new GCEvent.PinnedPlug(data.PlugStart, data.PlugEnd));
}
});
source.Clr.AddCallbackForEvent("GC/Mark", delegate (GCMarkWithTypeTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
stats.AddServerGCThreadFromMark(data.ThreadID, data.HeapNum);
GCEvent _event = stats.GetCurrentGC();
if (_event != null)
{
if (_event.PerHeapMarkTimes == null)
{
_event.PerHeapMarkTimes = new Dictionary<int, GCEvent.MarkInfo>();
}
if (!_event.PerHeapMarkTimes.ContainsKey(data.HeapNum))
{
_event.PerHeapMarkTimes.Add(data.HeapNum, new GCEvent.MarkInfo());
}
_event.PerHeapMarkTimes[data.HeapNum].MarkTimes[(int)data.Type] = data.TimeStampRelativeMSec;
_event.PerHeapMarkTimes[data.HeapNum].MarkPromoted[(int)data.Type] = data.Promoted;
}
});
source.Clr.AddCallbackForEvent("GC/GlobalHeapHistory", delegate (GCGlobalHeapHistoryTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
stats.ProcessGlobalHistory(data);
});
source.Clr.AddCallbackForEvent("GC/PerHeapHistory", delegate (GCPerHeapHistoryTraceData3 data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
stats.ProcessPerHeapHistory(data);
});
#if HAS_PRIVATE_GC_EVENTS
// See if the source knows about the CLR Private provider, if it does, then
var gcPrivate = new ClrPrivateTraceEventParser(source);
gcPrivate.GCPinPlugAtGCTime += delegate (PinPlugAtGCTimeTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc[data];
GCEvent _event = stats.GetCurrentGC();
if (_event != null)
{
// ObjectID is supposed to be an IntPtr. But "Address" is defined as UInt64 in
// TraceEvent.
_event.PinnedPlugs.Add(new GCEvent.PinnedPlug(data.PlugStart, data.PlugEnd));
}
};
// Sometimes at the end of a trace I see only some mark events are included in the trace and they
// are not in order, so need to anticipate that scenario.
gcPrivate.GCMarkStackRoots += delegate (GCMarkTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc[data];
stats.AddServerGCThreadFromMark(data.ThreadID, data.HeapNum);
GCEvent _event = stats.GetCurrentGC();
if (_event != null)
{
if (_event.PerHeapMarkTimes == null)
{
_event.PerHeapMarkTimes = new Dictionary<int, GCEvent.MarkInfo>();
}
if (!_event.PerHeapMarkTimes.ContainsKey(data.HeapNum))
{
_event.PerHeapMarkTimes.Add(data.HeapNum, new GCEvent.MarkInfo(false));
}
_event.PerHeapMarkTimes[data.HeapNum].MarkTimes[(int)MarkRootType.MarkStack] = data.TimeStampRelativeMSec;
}
};
gcPrivate.GCMarkFinalizeQueueRoots += delegate (GCMarkTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc[data];
GCEvent _event = stats.GetCurrentGC();
if (_event != null)
{
if ((_event.PerHeapMarkTimes != null) && _event.PerHeapMarkTimes.ContainsKey(data.HeapNum))
{
_event.PerHeapMarkTimes[data.HeapNum].MarkTimes[(int)MarkRootType.MarkFQ] =
data.TimeStampRelativeMSec;
}
}
};
gcPrivate.GCMarkHandles += delegate (GCMarkTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc[data];
GCEvent _event = stats.GetCurrentGC();
if (_event != null)
{
if ((_event.PerHeapMarkTimes != null) && _event.PerHeapMarkTimes.ContainsKey(data.HeapNum))
{
_event.PerHeapMarkTimes[data.HeapNum].MarkTimes[(int)MarkRootType.MarkHandles] =
data.TimeStampRelativeMSec;
}
}
};
gcPrivate.GCMarkCards += delegate (GCMarkTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc[data];
GCEvent _event = stats.GetCurrentGC();
if (_event != null)
{
if ((_event.PerHeapMarkTimes != null) && _event.PerHeapMarkTimes.ContainsKey(data.HeapNum))
{
_event.PerHeapMarkTimes[data.HeapNum].MarkTimes[(int)MarkRootType.MarkOlder] =
data.TimeStampRelativeMSec;
}
}
};
gcPrivate.GCGlobalHeapHistory += delegate (GCGlobalHeapHistoryTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc[data];
stats.ProcessGlobalHistory(data);
};
gcPrivate.GCPerHeapHistory += delegate (GCPerHeapHistoryTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc[data];
stats.ProcessPerHeapHistory(data);
};
gcPrivate.GCBGCStart += delegate (GCNoUserDataTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc[data];
if (stats.currentBGC != null)
{
if (stats.backgroundGCThreads == null)
{
stats.backgroundGCThreads = new Dictionary<int, object>(16);
}
stats.backgroundGCThreads[data.ThreadID] = null;
}
};
#endif
source.Clr.AddCallbackForEvent("GC/Stop", delegate (GCEndTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
GCEvent _event = stats.GetCurrentGC();
if (_event != null)
{
_event.GCDurationMSec = data.TimeStampRelativeMSec - _event.GCStartRelativeMSec;
_event.GCGeneration = data.Depth;
_event.GCEnd();
}
});
source.Clr.AddCallbackForEvent("GC/HeapStats", delegate (GCHeapStatsTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
GCEvent _event = stats.GetCurrentGC();
var sizeAfterMB = (data.GenerationSize1 + data.GenerationSize2 + data.GenerationSize3) / 1000000.0;
if (_event != null)
{
_event.HeapStats = (GCHeapStatsTraceData)data.Clone();
if (_event.Type == GCType.BackgroundGC)
{
_event.ProcessCpuMSec = stats.ProcessCpuMSec - _event.ProcessCpuAtLastGC;
_event.DurationSinceLastRestartMSec = data.TimeStampRelativeMSec - stats.lastRestartEndTimeRelativeMSec;
}
else
{
_event.ProcessCpuMSec = stats.ProcessCpuMSec - stats.ProcessCpuAtLastGC;
_event.DurationSinceLastRestartMSec = _event.PauseStartRelativeMSec - stats.lastRestartEndTimeRelativeMSec;
}
if (stats.HasAllocTickEvents)
{
_event.HasAllocTickEvents = true;
_event.AllocedSinceLastGCBasedOnAllocTickMB[0] = stats.allocTickCurrentMB[0] - stats.allocTickAtLastGC[0];
_event.AllocedSinceLastGCBasedOnAllocTickMB[1] = stats.allocTickCurrentMB[1] - stats.allocTickAtLastGC[1];
}
// This is where a background GC ends.
if ((_event.Type == GCType.BackgroundGC) && (stats.currentBGC != null))
{
stats.currentBGC.isComplete = true;
stats.lastCompletedGC = stats.currentBGC;
stats.currentBGC = null;
}
if (_event.isConcurrentGC)
{
Debug.Assert(_event.is20Event);
_event.isComplete = true;
stats.lastCompletedGC = _event;
}
}
stats.ProcessCpuAtLastGC = stats.ProcessCpuMSec;
stats.allocTickAtLastGC[0] = stats.allocTickCurrentMB[0];
stats.allocTickAtLastGC[1] = stats.allocTickCurrentMB[1];
stats.lastRestartEndTimeRelativeMSec = data.TimeStampRelativeMSec;
});
source.Clr.AddCallbackForEvent("GC/TerminateConcurrentThread", delegate (GCTerminateConcurrentThreadTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc.GetOrCreate(data.ProcessID);
if (stats.backgroundGCThreads != null)
{
stats.backgroundGCThreads = null;
}
});
#if HAS_PRIVATE_GC_EVENTS
gcPrivate.GCBGCAllocWaitStart += delegate (BGCAllocWaitTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc[data];
Debug.Assert(stats.currentBGC != null);
if (stats.currentBGC != null)
{
stats.currentBGC.AddLOHWaitThreadInfo(data.ThreadID, data.TimeStampRelativeMSec, data.Reason, true);
}
};
gcPrivate.GCBGCAllocWaitStop += delegate (BGCAllocWaitTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess stats = perProc[data];
GCEvent _event = stats.GetLastBGC();
if (_event != null)
{
_event.AddLOHWaitThreadInfo(data.ThreadID, data.TimeStampRelativeMSec, data.Reason, false);
}
};
gcPrivate.GCJoin += delegate (GCJoinTraceData data)
{
if (filterFunc != null && !filterFunc.Invoke(data))
{
return;
}
GCProcess gcProcess = perProc[data];
GCEvent _event = gcProcess.GetCurrentGC();
if (_event != null)
{
_event.AddGcJoin(data);
}
};
source.Process();
#endif
return perProc;
}
