private void Start(DiagnoserActionParameters parameters)
{
var counters = benchmarkToCounters[parameters.BenchmarkCase] = parameters.Config
.GetHardwareCounters()
.Select(counter => HardwareCounters.FromCounter(counter, config.IntervalSelectors.TryGetValue(counter, out var selector) ? selector : GetInterval))
.ToArray();
if (counters.Any()) // we need to enable the counters before starting the kernel session
{
HardwareCounters.Enable(counters);
}
try
{
kernelSession = new KernelSession(parameters, config, CreationTime).EnableProviders();
if (config.CreateHeapSession)
{
heapSession = new HeapSession(parameters, config, CreationTime).EnableProviders();
}
userSession = new UserSession(parameters, config, CreationTime).EnableProviders();
}
catch (Exception)
{
userSession?.Dispose();
heapSession?.Dispose();
kernelSession?.Dispose();
throw;
}
}
protected void Start(DiagnoserActionParameters parameters)
{
Clear();
BenchmarkToProcess.Add(parameters.BenchmarkCase, parameters.Process.Id);
StatsPerProcess.TryAdd(parameters.Process.Id, GetInitializedStats(parameters));
// Important: Must wire-up clean-up events prior to acquiring IDisposable instance (Session property)
// This is in effect the inverted sequence of actions in the Stop() method.
Console.CancelKeyPress += OnConsoleCancelKeyPress;
AppDomain.CurrentDomain.ProcessExit += OnProcessExit;
Session = CreateSession(parameters.BenchmarkCase);
EnableProvider();
AttachToEvents(Session, parameters.BenchmarkCase);
// The ETW collection thread starts receiving events immediately, but we only
// start aggregating them after ProcessStarted is called and we know which process
// (or processes) we should be monitoring. Communication between the benchmark thread
// and the ETW collection thread is through the statsPerProcess concurrent dictionary
// and through the TraceEventSession class, which is thread-safe.
var task = Task.Factory.StartNew((Action)(() => Session.Source.Process()), TaskCreationOptions.LongRunning);
// wait until the processing has started, block by then so we don't loose any
// information (very important for jit-related things)
WaitUntilStarted(task);
}
private void Stop(DiagnoserActionParameters parameters)
{
WaitForDelayedEvents();
string userSessionFile;
try
{
kernelSession.Stop();
heapSession?.Stop();
userSession.Stop();
userSessionFile = userSession.FilePath;
}
finally
{
kernelSession.Dispose();
heapSession?.Dispose();
userSession.Dispose();
}
// Merge the 'primary' etl file X.etl (userSession) with any files that match .clr*.etl .user*.etl. and .kernel.etl.
TraceEventSession.MergeInPlace(userSessionFile, TextWriter.Null);
benchmarkToEtlFile[parameters.BenchmarkCase] = userSessionFile;
}
private void StartTraceSession(DiagnoserActionParameters parameters)
{
var metricProviders = CompetitionCore.RunState[parameters.Config].Config
.GetMetrics()
.Select(m => m.ValuesProvider)
.OfType <IEtwMetricValueProvider>()
.Distinct()
.ToArray();
if (metricProviders.Length == 0)
{
_analysis = null;
return;
}
var analysis = CreateAnalysis(parameters.Benchmark, parameters.Config, metricProviders);
EtwHelpers.WorkaroundEnsureNativeDlls();
bool allOk = false;
try
{
BuildTraceSession(analysis);
allOk = true;
}
finally
{
if (!allOk)
{
CompleteTraceSession(analysis);
DisposeAnalysis(analysis);
}
}
}
protected void Start(DiagnoserActionParameters parameters)
{
Clear();
BenchmarkToProcess.Add(parameters.BenchmarkCase, parameters.Process.Id);
StatsPerProcess.TryAdd(parameters.Process.Id, GetInitializedStats(parameters));
Session = CreateSession(parameters.BenchmarkCase);
Console.CancelKeyPress += OnConsoleCancelKeyPress;
NativeWindowsConsoleHelper.OnExit += OnConsoleCancelKeyPress;
EnableProvider();
AttachToEvents(Session, parameters.BenchmarkCase);
// The ETW collection thread starts receiving events immediately, but we only
// start aggregating them after ProcessStarted is called and we know which process
// (or processes) we should be monitoring. Communication between the benchmark thread
// and the ETW collection thread is through the statsPerProcess concurrent dictionary
// and through the TraceEventSession class, which is thread-safe.
var task = Task.Factory.StartNew((Action)(() => Session.Source.Process()), TaskCreationOptions.LongRunning);
// wait until the processing has started, block by then so we don't loose any
// information (very important for jit-related things)
WaitUntilStarted(task);
}
protected override PmcStats GetInitializedStats(DiagnoserActionParameters parameters)
{
var stats = new PmcStats(
parameters.Config.GetHardwareCounters().ToArray(),
counter => HardwareCounters.FromCounter(counter, info => info.MinInterval)); // for this diagnoser we want the smallest interval to have best possible precision
HardwareCounters.Enable(stats.Counters.Values);
return(stats);
}
/// <inheritdoc />
public void Handle(HostSignal signal, DiagnoserActionParameters parameters)
{
switch (signal)
{
case HostSignal.BeforeMainRun:
try
{
var startInfo = new ProcessStartInfo(
@"C:\Users\chris\AppData\Local\JetBrains\Installations\dotTrace11\ConsoleProfiler.exe",
$"attach {parameters.Process.Id} --save-to={_saveLocation} --profiling-type=Sampling")
{
RedirectStandardError = true,
RedirectStandardOutput = true,
WindowStyle = ProcessWindowStyle.Normal,
UseShellExecute = false,
};
Console.WriteLine(startInfo.FileName);
Console.WriteLine(startInfo.Arguments);
_process = new Process
{
StartInfo = startInfo
};
_process.ErrorDataReceived += (sender, eventArgs) => Console.Error.WriteLine(eventArgs.Data);
_process.OutputDataReceived += (sender, eventArgs) => Console.WriteLine(eventArgs.Data);
_process.Start();
_process.BeginErrorReadLine();
_process.BeginOutputReadLine();
_process.Exited += (sender, args) =>
{
_process.Dispose();
};
}
catch (Exception e)
{
Console.Error.WriteLine(e.StackTrace);
throw;
}
break;
case HostSignal.AfterMainRun:
break;
case HostSignal.BeforeAnythingElse:
break;
case HostSignal.AfterAll:
break;
case HostSignal.SeparateLogic:
break;
default:
throw new ArgumentOutOfRangeException(nameof(signal), signal, null);
}
}
public void Handle(HostSignal signal, DiagnoserActionParameters parameters)
{
if (signal == HostSignal.BeforeAnythingElse)
{
Start(parameters);
}
else if (signal == HostSignal.AfterAll)
{
Stop();
}
}
public void Handle(HostSignal signal, DiagnoserActionParameters parameters)
{
if (signal == HostSignal.AfterProcessExit)
{
System.IO.File.Delete(MarkerFileName);
}
else if (signal == HostSignal.BeforeProcessStart)
{
System.IO.File.CreateText(MarkerFileName).Dispose();
}
}
public void Handle(HostSignal signal, DiagnoserActionParameters parameters)
{
if (signal == HostSignal.BeforeGeneralRun)
{
Start(parameters);
}
else if (signal == HostSignal.AfterGeneralRun)
{
Stop();
}
}
public void Handle(HostSignal signal, DiagnoserActionParameters parameters)
{
switch (signal)
{
case HostSignal.AfterActualRun:
this.TotalMemory = GC.GetTotalMemory(true);
break;
default:
break;
}
}
protected override PmcStats GetInitializedStats(DiagnoserActionParameters parameters)
{
var stats = new PmcStats(parameters.Config.GetHardwareCounters().ToArray());
var counters = stats.Counters.Values;
TraceEventProfileSources.Set( // it's a must have to get the events enabled!!
counters.Select(counter => counter.ProfileSourceId).ToArray(),
counters.Select(counter => counter.Interval).ToArray());
return(stats);
}
public void Handle(HostSignal signal, DiagnoserActionParameters parameters)
{
// it's crucial to start the trace before the process starts and stop it after the benchmarked process stops to have all of the necessary events in the trace file!
if (signal == HostSignal.BeforeProcessStart)
{
Start(parameters);
}
else if (signal == HostSignal.AfterProcessExit)
{
Stop(parameters);
}
}
public void Handle(HostSignal signal, DiagnoserActionParameters parameters)
{
if (signal == HostSignal.BeforeActualRun)
{
userStart = proc.UserProcessorTime.Ticks;
privStart = proc.PrivilegedProcessorTime.Ticks;
}
if (signal == HostSignal.AfterActualRun)
{
userEnd = proc.UserProcessorTime.Ticks;
privEnd = proc.PrivilegedProcessorTime.Ticks;
}
}
private const int CommonSenseLimit = 1024; // for benchmarks that use args like "new string('a', 200_000)"
internal static string GetTraceFilePath(DiagnoserActionParameters details, DateTime creationTime, string fileExtension)
{
string nameNoLimit = GetFilePathNoLimits(details, creationTime, fileExtension);
int limit = PathFeatures.AreAllLongPathsAvailable() ? CommonSenseLimit : WindowsOldPathLimit;
if (nameNoLimit.Length <= limit)
{
return(nameNoLimit);
}
return(GetLimitedFilePath(details, creationTime, fileExtension, limit));
}
private static string GetFilePath(string fileName, DiagnoserActionParameters details, DateTime creationTime, string fileExtension)
{
// if we run for more than one toolchain, the output file name should contain the name too so we can differ net462 vs netcoreapp2.1 etc
if (details.Config.GetJobs().Select(job => ToolchainExtensions.GetToolchain(job)).Distinct().Count() > 1)
{
fileName += $"-{details.BenchmarkCase.Job.Environment.Runtime?.Name ?? details.BenchmarkCase.GetToolchain()?.Name ?? details.BenchmarkCase.Job.Id}";
}
fileName += $"-{creationTime.ToString(BenchmarkRunnerClean.DateTimeFormat)}";
fileName = FolderNameHelper.ToFolderName(fileName);
return(Path.Combine(details.Config.ArtifactsPath, $"{fileName}.{fileExtension}"));
}
protected Session(string sessionName, DiagnoserActionParameters details, EtwProfilerConfig config, DateTime creationTime)
{
Details = details;
Config = config;
FilePath = ArtifactFileNameHelper.GetTraceFilePath(details, creationTime, FileExtension).EnsureFolderExists();
TraceEventSession = new TraceEventSession(sessionName, FilePath)
{
BufferSizeMB = config.BufferSizeInMb,
CpuSampleIntervalMSec = config.CpuSampleIntervalInMilliseconds,
};
Console.CancelKeyPress += OnConsoleCancelKeyPress;
AppDomain.CurrentDomain.ProcessExit += OnProcessExit;
}
/// <summary>Called after globalSetup, warmup and pilot but before the main run</summary>
/// <param name="parameters">The diagnoser action parameters</param>
public void BeforeMainRun(DiagnoserActionParameters parameters)
{
var analysis = _diagnoserState[parameters.Config].Analysis;
if (analysis == null)
{
return;
}
analysis.IterationGuid = Guid.NewGuid();
// Ensure delay before analysis start
Thread.Sleep(100);
DiagnoserEventSource.Instance.TraceStarted(analysis.RunGuid, analysis.IterationGuid);
}
/// <summary>Called after run, before global cleanup</summary>
public void BeforeGlobalCleanup(DiagnoserActionParameters parameters)
{
var analysis = _diagnoserState[parameters.Config].Analysis;
if (analysis == null)
{
return;
}
DiagnoserEventSource.Instance.TraceStopped(analysis.RunGuid, analysis.IterationGuid);
// Ensure delay after analysis stop
Thread.Sleep(100);
CompleteTraceSession(analysis);
}
public void Handle(HostSignal signal, DiagnoserActionParameters parameters)
{
if (signal == HostSignal.BeforeActualRun)
{
// reset counters
_data = new EventData();
EnableEvents(_quicEventSource, EventLevel.Verbose);
}
if (signal == HostSignal.AfterActualRun)
{
DisableEvents(_quicEventSource);
}
}
private void Stop(DiagnoserActionParameters parameters)
{
try
{
kernelSession.Stop();
userSession.Stop();
benchmarkToEtlFile[parameters.BenchmarkCase] = userSession.MergeFiles(kernelSession);
}
finally
{
kernelSession.Dispose();
userSession.Dispose();
}
}
protected Session(string sessionName, DiagnoserActionParameters details, EtwProfilerConfig config, DateTime creationTime)
{
Details = details;
Config = config;
FilePath = EnsureFolderExists(GetFilePath(details, creationTime));
TraceEventSession = new TraceEventSession(sessionName, FilePath)
{
BufferSizeMB = config.BufferSizeInMb,
CpuSampleIntervalMSec = config.CpuSampleIntervalInMiliseconds
};
Console.CancelKeyPress += OnConsoleCancelKeyPress;
NativeWindowsConsoleHelper.OnExit += OnConsoleCancelKeyPress;
}
private const int CommonSenseLimit = 1024; // for benchmarks that use args like "new string('a', 200_000)"
internal static string GetTraceFilePath(DiagnoserActionParameters details, DateTime creationTime, string fileExtension)
{
string nameNoLimit = GetFilePathNoLimits(details, creationTime, fileExtension);
// long paths can be enabled on Windows but it does not mean that ETW is going to work fine..
// so we always use 260 as limit on Windows
int limit = RuntimeInformation.IsWindows()
? WindowsOldPathLimit - "userheap.etl".Length // the session files get merged, they need to have same name (without extension)
: CommonSenseLimit;
if (nameNoLimit.Length <= limit)
{
return(nameNoLimit);
}
return(GetLimitedFilePath(details, creationTime, fileExtension, limit));
}
/// <summary>Creates a new instance of <see cref="InProcessHost"/>.</summary>
/// <param name="benchmarkCase">Current benchmark.</param>
/// <param name="logger">Logger for informational output.</param>
/// <param name="diagnoser">Diagnosers, if attached.</param>
/// <param name="config">Current config.</param>
public InProcessHost(BenchmarkCase benchmarkCase, ILogger logger, IDiagnoser diagnoser, IConfig config)
{
if (benchmarkCase == null)
{
throw new ArgumentNullException(nameof(benchmarkCase));
}
this.logger = logger ?? throw new ArgumentNullException(nameof(logger));
this.diagnoser = diagnoser;
IsDiagnoserAttached = diagnoser != null;
Config = config;
if (diagnoser != null)
{
diagnoserActionParameters = new DiagnoserActionParameters(
Process.GetCurrentProcess(),
benchmarkCase,
public void Handle(HostSignal signal, DiagnoserActionParameters parameters)
{
switch (signal)
{
case HostSignal.BeforeActualRun:
this.StartTime = DateTime.Now;
this.StartProcessorTime = parameters.Process.TotalProcessorTime;
break;
case HostSignal.AfterActualRun:
this.EndTime = DateTime.Now;
this.EndProcessorTime = parameters.Process.TotalProcessorTime;
break;
default:
break;
}
}
public void Handle(HostSignal signal, DiagnoserActionParameters parameters)
{
//Only turn on the recording of information at certain points.
//For example, ignore the warm up, etc.
switch (signal)
{
case HostSignal.BeforeActualRun:
_uowLogInterceptor.StartReading();
break;
case HostSignal.AfterActualRun:
_uowLogInterceptor.StopReading();
break;
default:
break;
}
}
public void OnWindowsWeMustAlwaysUseOldLongPathsLimitForSessionFiles()
{
var config = DefaultConfig.Instance
.WithArtifactsPath(@"C:\Projects\performance\artifacts\bin\MicroBenchmarks\Release\netcoreapp5.0\BenchmarkDotNet.Artifacts");
var benchmarkCase = BenchmarkConverter.TypeToBenchmarks(typeof(RentReturnArrayPoolTests <byte>), config).BenchmarksCases.First();
var parameters = new DiagnoserActionParameters(
process: null,
benchmarkCase: benchmarkCase,
new BenchmarkId(0, benchmarkCase));
foreach (string fileExtension in new[] { "etl", "kernel.etl", "userheap.etl" })
{
var traceFilePath = ArtifactFileNameHelper.GetTraceFilePath(parameters, new System.DateTime(2020, 10, 1), fileExtension);
Assert.InRange(actual: traceFilePath.Length, low: 0, high: 260);
}
}
public SynchronousProcessOutputLoggerWithDiagnoser(ILogger logger, Process process, IDiagnoser diagnoser, BenchmarkCase benchmarkCase, BenchmarkId benchmarkId, IConfig config)
{
if (!process.StartInfo.RedirectStandardOutput)
{
throw new NotSupportedException("set RedirectStandardOutput to true first");
}
if (!process.StartInfo.RedirectStandardInput)
{
throw new NotSupportedException("set RedirectStandardInput to true first");
}
this.logger = logger;
this.process = process;
this.diagnoser = diagnoser;
diagnoserActionParameters = new DiagnoserActionParameters(process, benchmarkCase, benchmarkId, config);
LinesWithResults = new List <string>();
LinesWithExtraOutput = new List <string>();
}
protected override PmcStats GetInitializedStats(DiagnoserActionParameters parameters)
{
var stats = new PmcStats(parameters.Config.GetHardwareCounters().ToArray(), FromCounter);
var counters = stats.Counters.Values;
try
{
TraceEventProfileSources.Set( // it's a must have to get the events enabled!!
counters.Select(counter => counter.ProfileSourceId).ToArray(),
counters.Select(counter => counter.Interval).ToArray());
}
catch (System.Runtime.InteropServices.COMException ex) when(ex.Message.StartsWith("The WMI data block or event notification has already been enabled"))
{
// previous run was interrupted by ctrl+c and never stopped
}
return(stats);
}
private static string GetLimitedFilePath(DiagnoserActionParameters details, DateTime creationTime, string fileExtension, int limit)
{
string shortTypeName = FolderNameHelper.ToFolderName(details.BenchmarkCase.Descriptor.Type, includeNamespace: false);
string methodName = details.BenchmarkCase.Descriptor.WorkloadMethod.Name;
string parameters = details.BenchmarkCase.HasParameters
? $"-hash{Hashing.HashString(FullNameProvider.GetMethodName(details.BenchmarkCase))}"
: string.Empty;
string fileName = $@"{shortTypeName}.{methodName}{parameters}";
string finalResult = GetFilePath(fileName, details, creationTime, fileExtension);
if (finalResult.Length > limit)
{
throw new NotSupportedException($"The full benchmark name: \"{fileName}\" combined with artifacts path: \"{details.Config.ArtifactsPath}\" is too long. " +
$"Please set the value of {nameof(details.Config)}.{nameof(details.Config.ArtifactsPath)} to shorter path or rename the type or method.");
}
return(finalResult);
}
