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 static async Task <bool> TEST_StandardConnectionStillWorksIfReverseConnectionIsBroken()
{
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
await RunSubprocess(
serverName : serverName,
duringExecution : async(int pid) =>
{
var config = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream stream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
using var source = new EventPipeEventSource(stream);
Task readerTask = Task.Run(() => source.Process());
await Task.Delay(500);
Logger.logger.Log("Stopping EventPipeSession over standard connection");
EventPipeClient.StopTracing(pid, sessionId);
await readerTask;
Logger.logger.Log("Stopped EventPipeSession over standard connection");
}
);
return(true);
}
protected override async Task ExecuteAsync(CancellationToken cancellationToken)
{
await Task.Yield();
var providerList = new List <Provider>()
{
new Provider(name: "Microsoft-Extensions-Logging",
keywords: (ulong)LoggingEventSource.Keywords.FormattedMessage,
eventLevel: EventLevel.LogAlways)
};
var configuration = new SessionConfiguration(
circularBufferSizeMB: 1000,
outputPath: "",
providers: providerList);
var binaryReader = EventPipeClient.CollectTracing(_options.ProcessId, configuration, out var sessionId);
var source = new EventPipeEventSource(binaryReader);
source.Dynamic.AddCallbackForProviderEvent("Microsoft-Extensions-Logging", "FormattedMessage", (traceEvent) =>
{
// Level, FactoryID, LoggerName, EventID, EventName, FormattedMessage
var categoryName = (string)traceEvent.PayloadValue(2);
if (!loggerCache.ContainsKey(categoryName))
{
loggerCache.TryAdd(categoryName, _loggerFactory.CreateLogger(categoryName));
}
if (loggerCache.TryGetValue(categoryName, out var logger))
{
var logLevel = (LogLevel)traceEvent.PayloadValue(0);
switch (logLevel)
{
case LogLevel.Trace:
logger.LogTrace((string)traceEvent.PayloadValue(4));
break;
case LogLevel.Debug:
logger.LogDebug((string)traceEvent.PayloadValue(4));
break;
case LogLevel.Information:
logger.LogInformation((string)traceEvent.PayloadValue(4));
break;
case LogLevel.Warning:
logger.LogWarning((string)traceEvent.PayloadValue(4));
break;
case LogLevel.Error:
logger.LogError((string)traceEvent.PayloadValue(4));
break;
case LogLevel.Critical:
logger.LogCritical((string)traceEvent.PayloadValue(4));
break;
}
}
});
source.Process();
_lifetime.StopApplication();
}
public static async Task <bool> TEST_ReverseConnectionCanRecycleWhileTracing()
{
bool fSuccess = true;
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
Task <bool> subprocessTask = Utils.RunSubprocess(
currentAssembly: Assembly.GetExecutingAssembly(),
environment: new Dictionary <string, string>
{
{ Utils.DiagnosticsMonitorAddressEnvKey, serverName },
{ Utils.DiagnosticsMonitorPauseOnStartEnvKey, "0" }
},
duringExecution: async(int pid) =>
{
ManualResetEvent mre = new ManualResetEvent(false);
Task regularTask = Task.Run(async() =>
{
try
{
var config = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream stream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
using var source = new EventPipeEventSource(stream);
Task readerTask = Task.Run(() => source.Process());
await Task.Delay(500);
Logger.logger.Log("Stopping EventPipeSession over standard connection");
EventPipeClient.StopTracing(pid, sessionId);
await readerTask;
Logger.logger.Log("Stopped EventPipeSession over standard connection");
}
finally
{
mre.Set();
}
});
Task reverseTask = Task.Run(async() =>
{
while (!mre.WaitOne(0))
{
var ad1 = await ReverseServer.CreateServerAndReceiveAdvertisement(serverName);
Logger.logger.Log(ad1.ToString());
}
});
await Task.WhenAll(reverseTask, regularTask);
}
);
fSuccess &= await subprocessTask;
return(fSuccess);
}
// Use EventPipe CollectTracing command to start monitoring. This may throw.
private EventPipeEventSource RequestTracingV1(string providerString)
{
var configuration = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: Trace.Extensions.ToProviders(providerString));
var binaryReader = EventPipeClient.CollectTracing(_processId, configuration, out _sessionId);
return(new EventPipeEventSource(binaryReader));
}
public static async Task <bool> TEST_CanConnectServerAndClientAtSameTime()
{
bool fSuccess = true;
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
var server = new ReverseServer(serverName);
Task <bool> subprocessTask = Utils.RunSubprocess(
currentAssembly: Assembly.GetExecutingAssembly(),
environment: new Dictionary <string, string>
{
{ Utils.DiagnosticsMonitorAddressEnvKey, serverName },
{ Utils.DiagnosticsMonitorPauseOnStartEnvKey, "0" }
},
duringExecution: async(int pid) =>
{
Task reverseTask = Task.Run(async() =>
{
Logger.logger.Log($"Waiting for reverse connection");
Stream reverseStream = await server.AcceptAsync();
Logger.logger.Log("Got reverse connection");
IpcAdvertise advertise = IpcAdvertise.Parse(reverseStream);
Logger.logger.Log(advertise.ToString());
});
Task regularTask = Task.Run(async() =>
{
var config = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream stream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
using var source = new EventPipeEventSource(stream);
Task readerTask = Task.Run(() => source.Process());
await Task.Delay(500);
Logger.logger.Log("Stopping EventPipeSession over standard connection");
EventPipeClient.StopTracing(pid, sessionId);
await readerTask;
Logger.logger.Log("Stopped EventPipeSession over standard connection");
});
await Task.WhenAll(reverseTask, regularTask);
}
);
fSuccess &= await Utils.WaitTillTimeout(subprocessTask, TimeSpan.FromMinutes(1));
server.Shutdown();
return(fSuccess);
}
private static void Main(string[] args)
{
if (args.Length < 2)
{
Console.WriteLine("triggerdump <pid> <mem threshold in MB>");
}
else
{
pid = Convert.ToInt32(args[0]);
threshold = Convert.ToInt32(args[1]);
Task monitorTask = new Task(() =>
{
var prov = new List <Provider>();
prov.Add(new Provider("System.Runtime", filterData: "EventCounterIntervalSec=1"));
var configuration = new SessionConfiguration(
circularBufferSizeMB: 1000,
outputPath: "",
providers: prov);
var binaryReader = EventPipeClient.CollectTracing(Int32.Parse(args[0]), configuration, out _sessionId);
EventPipeEventSource source = new EventPipeEventSource(binaryReader);
source.Dynamic.All += Dynamic_All;
source.Process();
});
Task commandTask = new Task(() =>
{
while (true)
{
while (!Console.KeyAvailable)
{
}
ConsoleKey cmd = Console.ReadKey(true).Key;
if (cmd == ConsoleKey.Q)
{
break;
}
}
});
monitorTask.Start();
commandTask.Start();
commandTask.Wait();
try
{
EventPipeClient.StopTracing(Int32.Parse(args[0]), _sessionId);
}
catch (System.IO.EndOfStreamException) {}
}
}
public static async Task <bool> TEST_CanConnectServerAndClientAtSameTime()
{
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
var server = new ReverseServer(serverName);
await RunSubprocess(
serverName : serverName,
duringExecution : async(int pid) =>
{
Task reverseTask = Task.Run(async() =>
{
Logger.logger.Log($"Waiting for reverse connection");
Stream reverseStream = await server.AcceptAsync();
Logger.logger.Log("Got reverse connection");
IpcAdvertise advertise = IpcAdvertise.Parse(reverseStream);
Logger.logger.Log(advertise.ToString());
});
Task regularTask = Task.Run(async() =>
{
var config = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream stream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
using var source = new EventPipeEventSource(stream);
Task readerTask = Task.Run(() => source.Process());
await Task.Delay(500);
Logger.logger.Log("Stopping EventPipeSession over standard connection");
EventPipeClient.StopTracing(pid, sessionId);
await readerTask;
Logger.logger.Log("Stopped EventPipeSession over standard connection");
});
await Task.WhenAll(reverseTask, regularTask);
}
);
server.Shutdown();
return(true);
}
private void ProcessEventPipeEvents()
{
var configuration = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: GetProviders()
);
var binaryReader = EventPipeClient.CollectTracing(_processId, configuration, out var sessionId);
EventPipeEventSource source = new EventPipeEventSource(binaryReader);
RegisterListeners(source);
// this is a blocking call
source.Process();
}
public void Start()
{
var configuration = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: _providers
);
var binaryReader = EventPipeClient.CollectTracing(_pid, configuration, out _sessionId);
EventPipeEventSource source = new EventPipeEventSource(binaryReader);
source.Dynamic.All += ProcessEvents;
// this is a blocking call
source.Process();
}
public static async Task <bool> TEST_ReverseConnectionCanRecycleWhileTracing()
{
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
await RunSubprocess(
serverName : serverName,
duringExecution : async(int pid) =>
{
Task regularTask = Task.Run(async() =>
{
var config = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream stream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
using var source = new EventPipeEventSource(stream);
Task readerTask = Task.Run(() => source.Process());
await Task.Delay(500);
Logger.logger.Log("Stopping EventPipeSession over standard connection");
EventPipeClient.StopTracing(pid, sessionId);
await readerTask;
Logger.logger.Log("Stopped EventPipeSession over standard connection");
});
Task reverseTask = Task.Run(async() =>
{
var ad1 = await WaitTillTimeout(ReverseServer.CreateServerAndReceiveAdvertisement(serverName), TimeSpan.FromMilliseconds(_maxPollTimeMS));
Logger.logger.Log(ad1.ToString());
var ad2 = await WaitTillTimeout(ReverseServer.CreateServerAndReceiveAdvertisement(serverName), TimeSpan.FromMilliseconds(_maxPollTimeMS));
Logger.logger.Log(ad2.ToString());
var ad3 = await WaitTillTimeout(ReverseServer.CreateServerAndReceiveAdvertisement(serverName), TimeSpan.FromMilliseconds(_maxPollTimeMS));
Logger.logger.Log(ad3.ToString());
var ad4 = await WaitTillTimeout(ReverseServer.CreateServerAndReceiveAdvertisement(serverName), TimeSpan.FromMilliseconds(_maxPollTimeMS));
Logger.logger.Log(ad4.ToString());
});
await Task.WhenAll(reverseTask, regularTask);
}
);
return(true);
}
public void Start(ILogger logger)
{
var configuration = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: GetProviders()
);
var ports = EventPipeClient.ListAvailablePorts();
logger.LogDebug($"IPC available ports for the performance monitoring session: {string.Join("-", ports)}.");
using var binaryReader =
EventPipeClient.CollectTracing(Process.GetCurrentProcess().Id, configuration, out _sessionId);
using var source = new EventPipeEventSource(binaryReader);
source.Dynamic.All += ProcessEvents;
source.Process();
}
public void Start()
{
// single exe publishing not happy with trace package -- wait on https://github.com/dotnet/sdk/issues/3510
//return;
var configuration = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: _providers
);
var binaryReader = EventPipeClient.CollectTracing(_pid, configuration, out _sessionId);
EventPipeEventSource source = new EventPipeEventSource(binaryReader);
source.Dynamic.All += ProcessEvents;
// this is a blocking call
source.Process();
}
public static async Task <bool> TEST_ServerIsResilientToNoBufferAgent()
{
bool fSuccess = true;
// N.B. - this test is only testing behavior on Windows since Unix Domain Sockets get their buffer size from the
// system configuration and isn't set here. Tests passing on Windows should indicate it would pass on Unix systems as well.
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
var server = new ReverseServer(serverName, 0);
Task <bool> subprocessTask = Utils.RunSubprocess(
currentAssembly: Assembly.GetExecutingAssembly(),
environment: new Dictionary <string, string>
{
{ Utils.DiagnosticsMonitorAddressEnvKey, serverName },
{ Utils.DiagnosticsMonitorPauseOnStartEnvKey, "0" }
},
duringExecution: async(int pid) =>
{
var config = new SessionConfiguration(
circularBufferSizeMB: 10,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream stream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
using var source = new EventPipeEventSource(stream);
Task readerTask = Task.Run(() => source.Process());
await Task.Delay(500);
Logger.logger.Log("Stopping EventPipeSession over standard connection");
EventPipeClient.StopTracing(pid, sessionId);
await readerTask;
Logger.logger.Log("Stopped EventPipeSession over standard connection");
}
);
fSuccess &= await Utils.WaitTillTimeout(subprocessTask, TimeSpan.FromMinutes(1));
server.Shutdown();
return(fSuccess);
}
public static async Task <bool> TEST_ServerWorksIfClientDoesntAccept()
{
bool fSuccess = true;
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
var server = new ReverseServer(serverName);
Task <bool> subprocessTask = Utils.RunSubprocess(
currentAssembly: Assembly.GetExecutingAssembly(),
environment: new Dictionary <string, string>
{
{ Utils.DiagnosticsMonitorAddressEnvKey, serverName },
{ Utils.DiagnosticsMonitorPauseOnStartEnvKey, "0" }
},
duringExecution: async(int pid) =>
{
var config = new SessionConfiguration(
circularBufferSizeMB: 10,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream stream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
using var source = new EventPipeEventSource(stream);
Task readerTask = Task.Run(() => source.Process());
await Task.Delay(500);
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;
server.Shutdown();
return(true);
}
public static async Task <bool> TEST_ServerIsResilientToNoBufferAgent()
{
// N.B. - this test is only testing behavior on Windows since Unix Domain Sockets get their buffer size from the
// system configuration and isn't set here. Tests passing on Windows should indicate it would pass on Unix systems as well.
string serverName = ReverseServer.MakeServerAddress();
Logger.logger.Log($"Server name is '{serverName}'");
var server = new ReverseServer(serverName, 0);
await RunSubprocess(
serverName : serverName,
duringExecution : async(int pid) =>
{
var config = new SessionConfiguration(
circularBufferSizeMB: 10,
format: EventPipeSerializationFormat.NetTrace,
providers: new List <Provider> {
new Provider("Microsoft-DotNETCore-SampleProfiler")
});
Logger.logger.Log("Starting EventPipeSession over standard connection");
using Stream stream = EventPipeClient.CollectTracing(pid, config, out var sessionId);
Logger.logger.Log($"Started EventPipeSession over standard connection with session id: 0x{sessionId:x}");
using var source = new EventPipeEventSource(stream);
Task readerTask = Task.Run(() => source.Process());
await Task.Delay(500);
Logger.logger.Log("Stopping EventPipeSession over standard connection");
EventPipeClient.StopTracing(pid, sessionId);
await readerTask;
Logger.logger.Log("Stopped EventPipeSession over standard connection");
}
);
server.Shutdown();
return(true);
}
/// <summary>
/// Collects a diagnostic trace from a currently running process.
/// </summary>
/// <param name="ct">The cancellation token</param>
/// <param name="console"></param>
/// <param name="processId">The process to collect the trace from.</param>
/// <param name="output">The output path for the collected trace data.</param>
/// <param name="buffersize">Sets the size of the in-memory circular buffer in megabytes.</param>
/// <param name="providers">A list of EventPipe providers to be enabled. This is in the form 'Provider[,Provider]', where Provider is in the form: 'KnownProviderName[:Flags[:Level][:KeyValueArgs]]', and KeyValueArgs is in the form: '[key1=value1][;key2=value2]'</param>
/// <param name="profile">A named pre-defined set of provider configurations that allows common tracing scenarios to be specified succinctly.</param>
/// <param name="format">The desired format of the created trace file.</param>
/// <returns></returns>
private static async Task <int> Collect(CancellationToken ct, IConsole console, int processId, FileInfo output, uint buffersize, string providers, string profile, TraceFileFormat format)
{
try
{
Debug.Assert(output != null);
Debug.Assert(profile != null);
if (processId <= 0)
{
Console.Error.WriteLine("Process ID should not be negative.");
return(ErrorCodes.ArgumentError);
}
var selectedProfile = ListProfilesCommandHandler.DotNETRuntimeProfiles
.FirstOrDefault(p => p.Name.Equals(profile, StringComparison.OrdinalIgnoreCase));
if (selectedProfile == null)
{
Console.Error.WriteLine($"Invalid profile name: {profile}");
return(ErrorCodes.ArgumentError);
}
var providerCollection = Extensions.ToProviders(providers);
var profileProviders = new List <Provider>();
// If user defined a different key/level on the same provider via --providers option that was specified via --profile option,
// --providers option takes precedence. Go through the list of providers specified and only add it if it wasn't specified
// via --providers options.
if (selectedProfile.Providers != null)
{
foreach (Provider selectedProfileProvider in selectedProfile.Providers)
{
bool shouldAdd = true;
foreach (Provider providerCollectionProvider in providerCollection)
{
if (providerCollectionProvider.Name.Equals(selectedProfileProvider.Name))
{
shouldAdd = false;
break;
}
}
if (shouldAdd)
{
profileProviders.Add(selectedProfileProvider);
}
}
}
providerCollection.AddRange(profileProviders);
if (providerCollection.Count <= 0)
{
Console.Error.WriteLine("No providers were specified to start a trace.");
return(ErrorCodes.ArgumentError);
}
PrintProviders(providerCollection);
var process = Process.GetProcessById(processId);
var configuration = new SessionConfiguration(
circularBufferSizeMB: buffersize,
format: EventPipeSerializationFormat.NetTrace,
providers: providerCollection);
var shouldExit = new ManualResetEvent(false);
var failed = false;
var terminated = false;
ct.Register(() => shouldExit.Set());
ulong sessionId = 0;
using (Stream stream = EventPipeClient.CollectTracing(processId, configuration, out sessionId))
using (VirtualTerminalMode vTermMode = VirtualTerminalMode.TryEnable())
{
if (sessionId == 0)
{
Console.Error.WriteLine("Unable to create session.");
return(ErrorCodes.SessionCreationError);
}
var collectingTask = new Task(() => {
try
{
using (var fs = new FileStream(output.FullName, FileMode.Create, FileAccess.Write))
{
Console.Out.WriteLine($"Process : {process.MainModule.FileName}");
Console.Out.WriteLine($"Output File : {fs.Name}");
Console.Out.WriteLine($"\tSession Id: 0x{sessionId:X16}");
lineToClear = Console.CursorTop;
var buffer = new byte[16 * 1024];
while (true)
{
int nBytesRead = stream.Read(buffer, 0, buffer.Length);
if (nBytesRead <= 0)
{
break;
}
fs.Write(buffer, 0, nBytesRead);
ResetCurrentConsoleLine(vTermMode.IsEnabled);
Console.Out.Write($"\tRecording trace {GetSize(fs.Length)}");
Debug.WriteLine($"PACKET: {Convert.ToBase64String(buffer, 0, nBytesRead)} (bytes {nBytesRead})");
}
}
}
catch (Exception ex)
{
failed = true;
Console.Error.WriteLine($"[ERROR] {ex.ToString()}");
}
finally
{
terminated = true;
shouldExit.Set();
}
});
collectingTask.Start();
Console.Out.WriteLine("Press <Enter> or <Ctrl+C> to exit...");
do
{
while (!Console.KeyAvailable && !shouldExit.WaitOne(250))
{
}
} while (!shouldExit.WaitOne(0) && Console.ReadKey(true).Key != ConsoleKey.Enter);
if (!terminated)
{
EventPipeClient.StopTracing(processId, sessionId);
}
await collectingTask;
}
Console.Out.WriteLine();
Console.Out.WriteLine("Trace completed.");
if (format != TraceFileFormat.NetTrace)
{
TraceFileFormatConverter.ConvertToFormat(format, output.FullName);
}
return(failed ? ErrorCodes.TracingError : 0);
}
catch (Exception ex)
{
Console.Error.WriteLine($"[ERROR] {ex.ToString()}");
return(ErrorCodes.UnknownError);
}
}
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);
}
private int Validate()
{
var isClean = EnsureCleanEnvironment();
if (!isClean)
{
return(-1);
}
var processId = Process.GetCurrentProcess().Id;
Logger.logger.Log("Connecting to EventPipe...");
var binaryReader = EventPipeClient.CollectTracing(processId, _sessionConfiguration, out var eventpipeSessionId);
if (eventpipeSessionId == 0)
{
Logger.logger.Log("Failed to connect to EventPipe!");
return(-1);
}
Logger.logger.Log($"Connected to EventPipe with sessionID '0x{eventpipeSessionId:x}'");
// CollectTracing returns before EventPipe::Enable has returned, so the
// the sources we want to listen for may not have been enabled yet.
// We'll use this sentinel EventSource to check if Enable has finished
ManualResetEvent sentinelEventReceived = new ManualResetEvent(false);
var sentinelTask = new Task(() =>
{
Logger.logger.Log("Started sending sentinel events...");
while (!sentinelEventReceived.WaitOne(50))
{
SentinelEventSource.Log.SentinelEvent();
}
Logger.logger.Log("Stopped sending sentinel events");
});
sentinelTask.Start();
EventPipeEventSource source = null;
Func <int> optionalTraceValidationCallback = null;
var readerTask = new Task(() =>
{
Logger.logger.Log("Creating EventPipeEventSource...");
source = new EventPipeEventSource(binaryReader);
Logger.logger.Log("EventPipeEventSource created");
source.Dynamic.All += (eventData) =>
{
try
{
if (eventData.ProviderName == "SentinelEventSource")
{
if (!sentinelEventReceived.WaitOne(0))
{
Logger.logger.Log("Saw sentinel event");
}
sentinelEventReceived.Set();
}
else if (_actualEventCounts.TryGetValue(eventData.ProviderName, out _))
{
_actualEventCounts[eventData.ProviderName]++;
}
else
{
Logger.logger.Log($"Saw new provider '{eventData.ProviderName}'");
_actualEventCounts[eventData.ProviderName] = 1;
}
}
catch (Exception e)
{
Logger.logger.Log("Exception in Dynamic.All callback " + e.ToString());
}
};
Logger.logger.Log("Dynamic.All callback registered");
if (_optionalTraceValidator != null)
{
Logger.logger.Log("Running optional trace validator");
optionalTraceValidationCallback = _optionalTraceValidator(source);
Logger.logger.Log("Finished running optional trace validator");
}
Logger.logger.Log("Starting stream processing...");
source.Process();
Logger.logger.Log("Stopping stream processing");
Logger.logger.Log($"Dropped {source.EventsLost} events");
});
readerTask.Start();
sentinelEventReceived.WaitOne();
Logger.logger.Log("Starting event generating action...");
_eventGeneratingAction();
Logger.logger.Log("Stopping event generating action");
Logger.logger.Log("Sending StopTracing command...");
EventPipeClient.StopTracing(processId, eventpipeSessionId);
Logger.logger.Log("Finished StopTracing command");
readerTask.Wait();
Logger.logger.Log("Reader task finished");
foreach (var(provider, expectedCount) in _expectedEventCounts)
{
if (_actualEventCounts.TryGetValue(provider, out var actualCount))
{
if (!expectedCount.Validate(actualCount))
{
return(Fail($"Event count mismatch for provider \"{provider}\": expected {expectedCount}, but saw {actualCount}"));
}
}
else
{
return(Fail($"No events for provider \"{provider}\""));
}
}
if (optionalTraceValidationCallback != null)
{
Logger.logger.Log("Validating optional callback...");
return(optionalTraceValidationCallback());
}
else
{
return(100);
}
}
private async Task <int> StartMonitor()
{
if (_processId == 0)
{
_console.Error.WriteLine("ProcessId is required.");
return(1);
}
String providerString;
if (_counterList.Count == 0)
{
CounterProvider defaultProvider = null;
_console.Out.WriteLine($"counter_list is unspecified. Monitoring all counters by default.");
// Enable the default profile if nothing is specified
if (!KnownData.TryGetProvider("System.Runtime", out defaultProvider))
{
_console.Error.WriteLine("No providers or profiles were specified and there is no default profile available.");
return(1);
}
providerString = defaultProvider.ToProviderString(_interval);
filter.AddFilter("System.Runtime");
}
else
{
CounterProvider provider = null;
StringBuilder sb = new StringBuilder("");
for (var i = 0; i < _counterList.Count; i++)
{
string counterSpecifier = _counterList[i];
string[] tokens = counterSpecifier.Split('[');
string providerName = tokens[0];
if (!KnownData.TryGetProvider(providerName, out provider))
{
sb.Append(CounterProvider.SerializeUnknownProviderName(providerName, _interval));
}
else
{
sb.Append(provider.ToProviderString(_interval));
}
if (i != _counterList.Count - 1)
{
sb.Append(",");
}
if (tokens.Length == 1)
{
filter.AddFilter(providerName); // This means no counter filter was specified.
}
else
{
string counterNames = tokens[1];
string[] enabledCounters = counterNames.Substring(0, counterNames.Length - 1).Split(',');
filter.AddFilter(providerName, enabledCounters);
}
}
providerString = sb.ToString();
}
ManualResetEvent shouldExit = new ManualResetEvent(false);
var terminated = false;
writer.InitializeDisplay();
Task monitorTask = new Task(() => {
try
{
var configuration = new SessionConfiguration(
circularBufferSizeMB: 1000,
format: EventPipeSerializationFormat.NetTrace,
providers: Trace.Extensions.ToProviders(providerString));
var binaryReader = EventPipeClient.CollectTracing(_processId, configuration, out _sessionId);
EventPipeEventSource source = new EventPipeEventSource(binaryReader);
source.Dynamic.All += Dynamic_All;
source.Process();
}
catch (Exception ex)
{
Debug.WriteLine($"[ERROR] {ex.ToString()}");
}
finally
{
terminated = true; // This indicates that the runtime is done. We shouldn't try to talk to it anymore.
shouldExit.Set();
}
});
monitorTask.Start();
Console.CancelKeyPress += (sender, args) => {
args.Cancel = true;
shouldExit.Set();
};
while (!shouldExit.WaitOne(250))
{
while (true)
{
if (shouldExit.WaitOne(250))
{
StopMonitor();
return(0);
}
if (Console.KeyAvailable)
{
break;
}
}
ConsoleKey cmd = Console.ReadKey(true).Key;
if (cmd == ConsoleKey.Q)
{
break;
}
else if (cmd == ConsoleKey.P)
{
pauseCmdSet = true;
}
else if (cmd == ConsoleKey.R)
{
pauseCmdSet = false;
}
}
if (!terminated)
{
StopMonitor();
}
return(await Task.FromResult(0));
}
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);
}
private async Task <int> StartMonitor()
{
if (_processId == 0)
{
_console.Error.WriteLine("ProcessId is required.");
return(1);
}
if (_interval == 0)
{
_console.Error.WriteLine("refreshInterval is required.");
return(1);
}
String providerString;
if (_counterList.Count == 0)
{
CounterProvider defaultProvider = null;
_console.Out.WriteLine($"counter_list is unspecified. Monitoring all counters by default.");
// Enable the default profile if nothing is specified
if (!KnownData.TryGetProvider("System.Runtime", out defaultProvider))
{
_console.Error.WriteLine("No providers or profiles were specified and there is no default profile available.");
return(1);
}
providerString = defaultProvider.ToProviderString(_interval);
filter.AddFilter("System.Runtime");
}
else
{
CounterProvider provider = null;
StringBuilder sb = new StringBuilder("");
for (var i = 0; i < _counterList.Count; i++)
{
string counterSpecifier = _counterList[i];
string[] tokens = counterSpecifier.Split('[');
string providerName = tokens[0];
if (!KnownData.TryGetProvider(providerName, out provider))
{
sb.Append(CounterProvider.SerializeUnknownProviderName(providerName, _interval));
}
else
{
sb.Append(provider.ToProviderString(_interval));
}
if (i != _counterList.Count - 1)
{
sb.Append(",");
}
if (tokens.Length == 1)
{
filter.AddFilter(providerName); // This means no counter filter was specified.
}
else
{
string counterNames = tokens[1];
string[] enabledCounters = counterNames.Substring(0, counterNames.Length - 1).Split(',');
filter.AddFilter(providerName, enabledCounters);
}
}
providerString = sb.ToString();
}
var terminated = false;
Task monitorTask = new Task(() => {
var configuration = new SessionConfiguration(
circularBufferSizeMB: 1000,
outputPath: "",
providers: Trace.Extensions.ToProviders(providerString));
var binaryReader = EventPipeClient.CollectTracing(_processId, configuration, out _sessionId);
EventPipeEventSource source = new EventPipeEventSource(binaryReader);
writer.InitializeDisplay();
source.Dynamic.All += Dynamic_All;
source.Process();
terminated = true; // This indicates that the runtime is done. We shoudn't try to talk to it anymore.
});
Task commandTask = new Task(() =>
{
while (true)
{
while (!Console.KeyAvailable)
{
}
ConsoleKey cmd = Console.ReadKey(true).Key;
if (cmd == ConsoleKey.Q)
{
break;
}
else if (cmd == ConsoleKey.P)
{
pauseCmdSet = true;
}
else if (cmd == ConsoleKey.R)
{
pauseCmdSet = false;
}
}
});
monitorTask.Start();
commandTask.Start();
await commandTask;
if (!terminated)
{
try
{
EventPipeClient.StopTracing(_processId, _sessionId);
}
catch (System.IO.EndOfStreamException) {} // If the app we're monitoring exits abrubtly, this may throw in which case we just swallow the exception and exit gracefully.
}
return(0);
}
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);
}
/// <summary>
/// Collects a diagnostic trace from a currently running process.
/// </summary>
/// <param name="ct">The cancellation token</param>
/// <param name="console"></param>
/// <param name="processId">The process to collect the trace from.</param>
/// <param name="output">The output path for the collected trace data.</param>
/// <param name="buffersize">Sets the size of the in-memory circular buffer in megabytes.</param>
/// <param name="providers">A list of EventPipe providers to be enabled. This is in the form 'Provider[,Provider]', where Provider is in the form: 'KnownProviderName[:Flags[:Level][:KeyValueArgs]]', and KeyValueArgs is in the form: '[key1=value1][;key2=value2]'</param>
/// <param name="profile">A named pre-defined set of provider configurations that allows common tracing scenarios to be specified succinctly.</param>
/// <param name="format">The desired format of the created trace file.</param>
/// <returns></returns>
private static async Task <int> Collect(CancellationToken ct, IConsole console, int processId, FileInfo output, uint buffersize, string providers, string profile, TraceFileFormat format, TimeSpan duration)
{
try
{
Debug.Assert(output != null);
Debug.Assert(profile != null);
bool hasConsole = console.GetTerminal() != null;
if (hasConsole)
{
Console.Clear();
}
if (processId < 0)
{
Console.Error.WriteLine("Process ID should not be negative.");
return(ErrorCodes.ArgumentError);
}
else if (processId == 0)
{
Console.Error.WriteLine("--process-id is required");
return(ErrorCodes.ArgumentError);
}
if (profile.Length == 0 && providers.Length == 0)
{
Console.Out.WriteLine("No profile or providers specified, defaulting to trace profile 'cpu-sampling'");
profile = "cpu-sampling";
}
Dictionary <string, string> enabledBy = new Dictionary <string, string>();
var providerCollection = Extensions.ToProviders(providers);
foreach (Provider providerCollectionProvider in providerCollection)
{
enabledBy[providerCollectionProvider.Name] = "--providers ";
}
if (profile.Length != 0)
{
var selectedProfile = ListProfilesCommandHandler.DotNETRuntimeProfiles
.FirstOrDefault(p => p.Name.Equals(profile, StringComparison.OrdinalIgnoreCase));
if (selectedProfile == null)
{
Console.Error.WriteLine($"Invalid profile name: {profile}");
return(ErrorCodes.ArgumentError);
}
Profile.MergeProfileAndProviders(selectedProfile, providerCollection, enabledBy);
}
if (providerCollection.Count <= 0)
{
Console.Error.WriteLine("No providers were specified to start a trace.");
return(ErrorCodes.ArgumentError);
}
PrintProviders(providerCollection, enabledBy);
var process = Process.GetProcessById(processId);
var configuration = new SessionConfiguration(
circularBufferSizeMB: buffersize,
format: EventPipeSerializationFormat.NetTrace,
providers: providerCollection);
var shouldExit = new ManualResetEvent(false);
var shouldStopAfterDuration = duration != default(TimeSpan);
var failed = false;
var terminated = false;
System.Timers.Timer durationTimer = null;
ct.Register(() => shouldExit.Set());
ulong sessionId = 0;
using (Stream stream = EventPipeClient.CollectTracing(processId, configuration, out sessionId))
using (VirtualTerminalMode vTermMode = VirtualTerminalMode.TryEnable())
{
if (sessionId == 0)
{
Console.Error.WriteLine("Unable to create session.");
return(ErrorCodes.SessionCreationError);
}
if (shouldStopAfterDuration)
{
durationTimer = new System.Timers.Timer(duration.TotalMilliseconds);
durationTimer.Elapsed += (s, e) => shouldExit.Set();
durationTimer.AutoReset = false;
}
var collectingTask = new Task(() =>
{
try
{
var stopwatch = new Stopwatch();
durationTimer?.Start();
stopwatch.Start();
using (var fs = new FileStream(output.FullName, FileMode.Create, FileAccess.Write))
{
Console.Out.WriteLine($"Process : {process.MainModule.FileName}");
Console.Out.WriteLine($"Output File : {fs.Name}");
if (shouldStopAfterDuration)
{
Console.Out.WriteLine($"Trace Duration : {duration.ToString(@"dd\:hh\:mm\:ss")}");
}
Console.Out.WriteLine("\n\n");
var buffer = new byte[16 * 1024];
while (true)
{
int nBytesRead = stream.Read(buffer, 0, buffer.Length);
if (nBytesRead <= 0)
{
break;
}
fs.Write(buffer, 0, nBytesRead);
if (hasConsole)
{
lineToClear = Console.CursorTop - 1;
ResetCurrentConsoleLine(vTermMode.IsEnabled);
}
Console.Out.WriteLine($"[{stopwatch.Elapsed.ToString(@"dd\:hh\:mm\:ss")}]\tRecording trace {GetSize(fs.Length)}");
Console.Out.WriteLine("Press <Enter> or <Ctrl+C> to exit...");
Debug.WriteLine($"PACKET: {Convert.ToBase64String(buffer, 0, nBytesRead)} (bytes {nBytesRead})");
}
}
}
catch (Exception ex)
{
failed = true;
Console.Error.WriteLine($"[ERROR] {ex.ToString()}");
}
finally
{
terminated = true;
shouldExit.Set();
}
});
collectingTask.Start();
do
{
while (!Console.KeyAvailable && !shouldExit.WaitOne(250))
{
}
} while (!shouldExit.WaitOne(0) && Console.ReadKey(true).Key != ConsoleKey.Enter);
if (!terminated)
{
durationTimer?.Stop();
EventPipeClient.StopTracing(processId, sessionId);
}
await collectingTask;
}
Console.Out.WriteLine();
Console.Out.WriteLine("Trace completed.");
if (format != TraceFileFormat.NetTrace)
{
TraceFileFormatConverter.ConvertToFormat(format, output.FullName);
}
return(failed ? ErrorCodes.TracingError : 0);
}
catch (Exception ex)
{
Console.Error.WriteLine($"[ERROR] {ex.ToString()}");
return(ErrorCodes.UnknownError);
}
}
/// <summary>
/// Collects a diagnostic trace from a currently running process.
/// </summary>
/// <param name="sizeChangeCallbacks">size change callbacks</param>
/// <param name="tracing">To start / stop the tracing</param>
/// <param name="processId">The process to collect the trace from.</param>
/// <param name="output">The output path for the collected trace data.</param>
/// <param name="buffersize">Sets the size of the in-memory circular buffer in megabytes.</param>
/// <param name="providers">A list of EventPipe providers to be enabled. This is in the form 'Provider[,Provider]', where Provider is in the form: 'KnownProviderName[:Flags[:Level][:KeyValueArgs]]', and KeyValueArgs is in the form: '[key1=value1][;key2=value2]'</param>
/// <param name="profile">A named pre-defined set of provider configurations that allows common tracing scenarios to be specified succinctly.</param>
/// <param name="format">The desired format of the created trace file.</param>
/// <returns></returns>
public static async Task <int> Collect(ICollection <Action <long> > sizeChangeCallbacks, Tracing tracing,
FileInfo output, int processId = 0,
uint buffersize = 256,
string providers = "", Profile profile = null, TraceFileFormat format = TraceFileFormat.NetTrace)
{
if (processId <= 0)
{
processId = Process.GetCurrentProcess().Id;
}
if (profile == null)
{
profile = CpuSampling;
}
try
{
Debug.Assert(output != null);
if (processId <= 0)
{
throw new ArgumentException("Process ID should not be negative.");
}
IDictionary <string, string> enabledBy = new Dictionary <string, string>();
var providerCollection = ToProviders(providers);
foreach (var providerCollectionProvider in providerCollection)
{
enabledBy[providerCollectionProvider.Name] = "--providers ";
}
var profileProviders = new List <Provider>();
// If user defined a different key/level on the same provider via --providers option that was specified via --profile option,
// --providers option takes precedence. Go through the list of providers specified and only add it if it wasn't specified
// via --providers options.
if (profile.Providers != null)
{
foreach (var selectedProfileProvider in profile.Providers)
{
var shouldAdd = true;
foreach (var providerCollectionProvider in providerCollection)
{
if (!providerCollectionProvider.Name.Equals(selectedProfileProvider.Name))
{
continue;
}
shouldAdd = false;
break;
}
if (!shouldAdd)
{
continue;
}
enabledBy[selectedProfileProvider.Name] = "--profile ";
profileProviders.Add(selectedProfileProvider);
}
}
providerCollection.AddRange(profileProviders);
if (providerCollection.Count <= 0)
{
throw new ArgumentException("No providers were specified to start a trace.");
}
var process = Process.GetProcessById(processId);
var configuration = new SessionConfiguration(
circularBufferSizeMB: buffersize,
format: EventPipeSerializationFormat.NetTrace,
providers: providerCollection);
var failed = false;
var terminated = false;
using (var stream = EventPipeClient.CollectTracing(processId, configuration, out var sessionId))
{
if (sessionId == 0)
{
Console.Error.WriteLine("Unable to create session.");
return(ErrorCodes.SessionCreationError);
}
var collectingTask = new Task(() =>
{
try
{
using (var fs = new FileStream(output.FullName, FileMode.Create, FileAccess.Write))
{
Console.Out.WriteLine("\n\n");
var buffer = new byte[16 * 1024];
while (true)
{
var nBytesRead = stream.Read(buffer, 0, buffer.Length);
if (nBytesRead <= 0)
{
break;
}
fs.Write(buffer, 0, nBytesRead);
foreach (var sizeChangeCallback in sizeChangeCallbacks)
{
sizeChangeCallback(fs.Length);
}
/*Console.Out.WriteLine(
* $"[{stopwatch.Elapsed.ToString(@"dd\:hh\:mm\:ss")}]\tRecording trace {GetSize(fs.Length)}");*/
/*Debug.WriteLine(
* $"PACKET: {Convert.ToBase64String(buffer, 0, nBytesRead)} (bytes {nBytesRead})");*/
}
}
//if (format != TraceFileFormat.NetTrace)
// TraceFileFormatConverter.ConvertToFormat(format, output.FullName);
}
catch (Exception ex)
{
failed = true;
Console.Error.WriteLine($"[ERROR] {ex.ToString()}");
}
finally
{
terminated = true;
}
});
collectingTask.Start();
tracing.Wait();
EventPipeClient.StopTracing(processId, sessionId);
await collectingTask;
}
//tracing.SignalFinish(!failed);
return(failed ? ErrorCodes.TracingError : 0);
}
catch (Exception ex)
{
Console.Error.WriteLine($"[ERROR] {ex.ToString()}");
//tracing.SignalFinish(false);
return(ErrorCodes.UnknownError);
}
}
private int Validate()
{
// FIXME: This is a bandaid fix for a deadlock in EventPipeEventSource caused by
// the lazy caching in the Regex library. The caching creates a ConcurrentDictionary
// and because it is the first one in the process, it creates an EventSource which
// results in a deadlock over a lock in EventPipe. These lines should be removed once the
// underlying issue is fixed by forcing these events to try to be written _before_ we shutdown.
//
// see: https://github.com/dotnet/runtime/pull/1794 for details on the issue
//
var emptyConcurrentDictionary = new ConcurrentDictionary <string, string>();
emptyConcurrentDictionary["foo"] = "bar";
var __count = emptyConcurrentDictionary.Count;
var isClean = IpcTraceTest.EnsureCleanEnvironment();
if (!isClean)
{
return(-1);
}
// CollectTracing returns before EventPipe::Enable has returned, so the
// the sources we want to listen for may not have been enabled yet.
// We'll use this sentinel EventSource to check if Enable has finished
ManualResetEvent sentinelEventReceived = new ManualResetEvent(false);
var sentinelTask = new Task(() =>
{
Logger.logger.Log("Started sending sentinel events...");
while (!sentinelEventReceived.WaitOne(50))
{
SentinelEventSource.Log.SentinelEvent();
}
Logger.logger.Log("Stopped sending sentinel events");
});
sentinelTask.Start();
int processId = Process.GetCurrentProcess().Id;
object threadSync = new object(); // for locking eventpipeSessionId access
ulong eventpipeSessionId = 0;
Func <int> optionalTraceValidationCallback = null;
var readerTask = new Task(() =>
{
Logger.logger.Log("Connecting to EventPipe...");
using (var eventPipeStream = new StreamProxy(EventPipeClient.CollectTracing(processId, _sessionConfiguration, out var sessionId)))
{
if (sessionId == 0)
{
Logger.logger.Log("Failed to connect to EventPipe!");
throw new ApplicationException("Failed to connect to EventPipe");
}
Logger.logger.Log($"Connected to EventPipe with sessionID '0x{sessionId:x}'");
lock (threadSync)
{
eventpipeSessionId = sessionId;
}
Logger.logger.Log("Creating EventPipeEventSource...");
using (EventPipeEventSource source = new EventPipeEventSource(eventPipeStream))
{
Logger.logger.Log("EventPipeEventSource created");
source.Dynamic.All += (eventData) =>
{
try
{
if (eventData.ProviderName == "SentinelEventSource")
{
if (!sentinelEventReceived.WaitOne(0))
{
Logger.logger.Log("Saw sentinel event");
}
sentinelEventReceived.Set();
}
else if (_actualEventCounts.TryGetValue(eventData.ProviderName, out _))
{
_actualEventCounts[eventData.ProviderName]++;
}
else
{
Logger.logger.Log($"Saw new provider '{eventData.ProviderName}'");
_actualEventCounts[eventData.ProviderName] = 1;
}
}
catch (Exception e)
{
Logger.logger.Log("Exception in Dynamic.All callback " + e.ToString());
}
};
Logger.logger.Log("Dynamic.All callback registered");
if (_optionalTraceValidator != null)
{
Logger.logger.Log("Running optional trace validator");
optionalTraceValidationCallback = _optionalTraceValidator(source);
Logger.logger.Log("Finished running optional trace validator");
}
Logger.logger.Log("Starting stream processing...");
try
{
source.Process();
}
catch (Exception e)
{
Logger.logger.Log($"Exception thrown while reading; dumping culprit stream to disk...");
eventPipeStream.DumpStreamToDisk();
// rethrow it to fail the test
throw e;
}
Logger.logger.Log("Stopping stream processing");
Logger.logger.Log($"Dropped {source.EventsLost} events");
}
}
});
var waitSentinelEventTask = new Task(() => {
sentinelEventReceived.WaitOne();
});
readerTask.Start();
waitSentinelEventTask.Start();
// Will throw if the reader task throws any exceptions before signaling sentinelEventReceived.
Task.WaitAny(readerTask, waitSentinelEventTask);
Logger.logger.Log("Starting event generating action...");
_eventGeneratingAction();
Logger.logger.Log("Stopping event generating action");
var stopTask = Task.Run(() =>
{
Logger.logger.Log("Sending StopTracing command...");
lock (threadSync) // eventpipeSessionId
{
EventPipeClient.StopTracing(processId, eventpipeSessionId);
}
Logger.logger.Log("Finished StopTracing command");
});
// Should throw if the reader task throws any exceptions
Task.WaitAll(readerTask, stopTask);
Logger.logger.Log("Reader task finished");
foreach (var(provider, expectedCount) in _expectedEventCounts)
{
if (_actualEventCounts.TryGetValue(provider, out var actualCount))
{
if (!expectedCount.Validate(actualCount))
{
return(Fail($"Event count mismatch for provider \"{provider}\": expected {expectedCount}, but saw {actualCount}"));
}
}
else
{
return(Fail($"No events for provider \"{provider}\""));
}
}
if (optionalTraceValidationCallback != null)
{
Logger.logger.Log("Validating optional callback...");
// reader thread should be dead now, no need to lock
return(optionalTraceValidationCallback());
}
else
{
return(100);
}
}
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_CanStartAndStopSessionWhilepaused()
{
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) =>
{
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-DotNETRuntime", UInt64.MaxValue, 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);
await Task.Delay(TimeSpan.FromSeconds(1));
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");
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()}");
}
);
fSuccess &= await subprocessTask;
return(fSuccess);
}
/// <summary>
/// Collects a diagnostic trace from a currently running process.
/// </summary>
/// <param name="console"></param>
/// <param name="processId">The process to collect the trace from.</param>
/// <param name="output">The output path for the collected trace data.</param>
/// <param name="buffersize">Sets the size of the in-memory circular buffer in megabytes.</param>
/// <param name="providers">A list of EventPipe providers to be enabled. This is in the form 'Provider[,Provider]', where Provider is in the form: '(GUID|KnownProviderName)[:Flags[:Level][:KeyValueArgs]]', and KeyValueArgs is in the form: '[key1=value1][;key2=value2]'</param>
/// <param name="profile">A named pre-defined set of provider configurations that allows common tracing scenarios to be specified succinctly.</param>
/// <param name="format">The desired format of the created trace file.</param>
/// <returns></returns>
private static async Task <int> Collect(IConsole console, int processId, FileInfo output, uint buffersize, string providers, string profile, TraceFileFormat format)
{
try
{
if (output == null)
{
throw new ArgumentNullException(nameof(output));
}
if (processId <= 0)
{
throw new ArgumentException(nameof(processId));
}
if (profile == null)
{
throw new ArgumentNullException(nameof(profile));
}
var selectedProfile = ListProfilesCommandHandler.DotNETRuntimeProfiles
.FirstOrDefault(p => p.Name.Equals(profile, StringComparison.OrdinalIgnoreCase));
if (selectedProfile == null)
{
throw new ArgumentException($"Invalid profile name: {profile}");
}
var providerCollection = Extensions.ToProviders(providers);
if (selectedProfile.Providers != null)
{
providerCollection.AddRange(selectedProfile.Providers);
}
if (providerCollection.Count <= 0)
{
throw new ArgumentException("No providers were specified to start a trace.");
}
PrintProviders(providerCollection);
var process = Process.GetProcessById(processId);
var configuration = new SessionConfiguration(
circularBufferSizeMB: buffersize,
outputPath: null, // Not used on the streaming scenario.
providers: providerCollection);
var shouldExit = new ManualResetEvent(false);
ulong sessionId = 0;
using (Stream stream = EventPipeClient.CollectTracing(processId, configuration, out sessionId))
using (VirtualTerminalMode vTermMode = VirtualTerminalMode.TryEnable())
{
if (sessionId == 0)
{
Console.Error.WriteLine("Unable to create session.");
return(-1);
}
var collectingTask = new Task(() => {
using (var fs = new FileStream(output.FullName, FileMode.Create, FileAccess.Write))
{
Console.Out.WriteLine($"Process : {process.MainModule.FileName}");
Console.Out.WriteLine($"Output File : {fs.Name}");
Console.Out.WriteLine($"\tSession Id: 0x{sessionId:X16}");
lineToClear = Console.CursorTop;
while (true)
{
var buffer = new byte[16 * 1024];
int nBytesRead = stream.Read(buffer, 0, buffer.Length);
if (nBytesRead <= 0)
{
break;
}
fs.Write(buffer, 0, nBytesRead);
ResetCurrentConsoleLine(vTermMode.IsEnabled);
Console.Out.Write($"\tRecording trace {GetSize(fs.Length)}");
Debug.WriteLine($"PACKET: {Convert.ToBase64String(buffer, 0, nBytesRead)} (bytes {nBytesRead})");
}
}
});
collectingTask.Start();
Console.Out.WriteLine("Press <Enter> or <Ctrl+C> to exit...");
Console.CancelKeyPress += (sender, args) => {
args.Cancel = true;
shouldExit.Set();
};
do
{
while (!Console.KeyAvailable && !shouldExit.WaitOne(250))
{
}
} while (!shouldExit.WaitOne(0) && Console.ReadKey(true).Key != ConsoleKey.Enter);
EventPipeClient.StopTracing(processId, sessionId);
collectingTask.Wait();
}
Console.Out.WriteLine();
Console.Out.WriteLine("Trace completed.");
TraceFileFormatConverter.ConvertToFormat(format, output.FullName);
await Task.FromResult(0);
return(sessionId != 0 ? 0 : 1);
}
catch (Exception ex)
{
Console.Error.WriteLine($"[ERROR] {ex.ToString()}");
return(1);
}
}
private int Validate()
{
var isClean = EnsureCleanEnvironment();
if (!isClean)
{
return(-1);
}
// CollectTracing returns before EventPipe::Enable has returned, so the
// the sources we want to listen for may not have been enabled yet.
// We'll use this sentinel EventSource to check if Enable has finished
ManualResetEvent sentinelEventReceived = new ManualResetEvent(false);
var sentinelTask = new Task(() =>
{
Logger.logger.Log("Started sending sentinel events...");
while (!sentinelEventReceived.WaitOne(50))
{
SentinelEventSource.Log.SentinelEvent();
}
Logger.logger.Log("Stopped sending sentinel events");
});
sentinelTask.Start();
int processId = Process.GetCurrentProcess().Id;;
object threadSync = new object(); // for locking eventpipeSessionId access
ulong eventpipeSessionId = 0;
Func <int> optionalTraceValidationCallback = null;
var readerTask = new Task(() =>
{
Logger.logger.Log("Connecting to EventPipe...");
using (var eventPipeStream = new StreamProxy(EventPipeClient.CollectTracing(processId, _sessionConfiguration, out var sessionId)))
{
if (sessionId == 0)
{
Logger.logger.Log("Failed to connect to EventPipe!");
throw new ApplicationException("Failed to connect to EventPipe");
}
Logger.logger.Log($"Connected to EventPipe with sessionID '0x{sessionId:x}'");
lock (threadSync)
{
eventpipeSessionId = sessionId;
}
Logger.logger.Log("Creating EventPipeEventSource...");
using (EventPipeEventSource source = new EventPipeEventSource(eventPipeStream))
{
Logger.logger.Log("EventPipeEventSource created");
source.Dynamic.All += (eventData) =>
{
try
{
if (eventData.ProviderName == "SentinelEventSource")
{
if (!sentinelEventReceived.WaitOne(0))
{
Logger.logger.Log("Saw sentinel event");
}
sentinelEventReceived.Set();
}
else if (_actualEventCounts.TryGetValue(eventData.ProviderName, out _))
{
_actualEventCounts[eventData.ProviderName]++;
}
else
{
Logger.logger.Log($"Saw new provider '{eventData.ProviderName}'");
_actualEventCounts[eventData.ProviderName] = 1;
}
}
catch (Exception e)
{
Logger.logger.Log("Exception in Dynamic.All callback " + e.ToString());
}
};
Logger.logger.Log("Dynamic.All callback registered");
if (_optionalTraceValidator != null)
{
Logger.logger.Log("Running optional trace validator");
optionalTraceValidationCallback = _optionalTraceValidator(source);
Logger.logger.Log("Finished running optional trace validator");
}
Logger.logger.Log("Starting stream processing...");
try
{
source.Process();
}
catch (Exception e)
{
Logger.logger.Log($"Exception thrown while reading; dumping culprit stream to disk...");
eventPipeStream.DumpStreamToDisk();
// rethrow it to fail the test
throw e;
}
Logger.logger.Log("Stopping stream processing");
Logger.logger.Log($"Dropped {source.EventsLost} events");
}
}
});
readerTask.Start();
sentinelEventReceived.WaitOne();
Logger.logger.Log("Starting event generating action...");
_eventGeneratingAction();
Logger.logger.Log("Stopping event generating action");
var stopTask = Task.Run(() =>
{
Logger.logger.Log("Sending StopTracing command...");
lock (threadSync) // eventpipeSessionId
{
EventPipeClient.StopTracing(processId, eventpipeSessionId);
}
Logger.logger.Log("Finished StopTracing command");
});
// Should throw if the reader task throws any exceptions
Task.WaitAll(readerTask, stopTask);
Logger.logger.Log("Reader task finished");
foreach (var(provider, expectedCount) in _expectedEventCounts)
{
if (_actualEventCounts.TryGetValue(provider, out var actualCount))
{
if (!expectedCount.Validate(actualCount))
{
return(Fail($"Event count mismatch for provider \"{provider}\": expected {expectedCount}, but saw {actualCount}"));
}
}
else
{
return(Fail($"No events for provider \"{provider}\""));
}
}
if (optionalTraceValidationCallback != null)
{
Logger.logger.Log("Validating optional callback...");
// reader thread should be dead now, no need to lock
return(optionalTraceValidationCallback());
}
else
{
return(100);
}
}