static int InnerMain(FileInfo traceFile,
FileInfo outputFileName,
int?pid,
string processName,
PgoFileType?pgoFileType,
IEnumerable <FileInfo> reference,
int?clrInstanceId = null,
bool processJitEvents = true,
bool processR2REvents = true,
bool displayProcessedEvents = false,
bool validateOutputFile = true,
bool verboseWarnings = false,
jittraceoptions jitTraceOptions = jittraceoptions.sorted,
double excludeEventsBefore = 0,
double excludeEventsAfter = Double.MaxValue,
bool warnings = true)
{
s_reachedInnerMain = true;
if (traceFile == null)
{
PrintUsage("--trace-file must be specified");
return(-8);
}
if (outputFileName != null)
{
if (!pgoFileType.HasValue)
{
PrintUsage($"--pgo-file-type must be specified");
return(-9);
}
if ((pgoFileType.Value != PgoFileType.jittrace) && (pgoFileType != PgoFileType.mibc))
{
PrintUsage($"Invalid output pgo type {pgoFileType} specified.");
return(-9);
}
if (pgoFileType == PgoFileType.jittrace)
{
if (!outputFileName.Name.EndsWith(".jittrace"))
{
PrintUsage($"jittrace output file name must end with .jittrace");
return(-9);
}
}
if (pgoFileType == PgoFileType.mibc)
{
if (!outputFileName.Name.EndsWith(".mibc"))
{
PrintUsage($"jittrace output file name must end with .mibc");
return(-9);
}
}
}
string etlFileName = traceFile.FullName;
foreach (string nettraceExtension in new string[] { ".netperf", ".netperf.zip", ".nettrace" })
{
if (traceFile.FullName.EndsWith(nettraceExtension))
{
etlFileName = traceFile.FullName.Substring(0, traceFile.FullName.Length - nettraceExtension.Length) + ".etlx";
Console.WriteLine($"Creating ETLX file {etlFileName} from {traceFile.FullName}");
TraceLog.CreateFromEventPipeDataFile(traceFile.FullName, etlFileName);
}
}
string lttngExtension = ".trace.zip";
if (traceFile.FullName.EndsWith(lttngExtension))
{
etlFileName = traceFile.FullName.Substring(0, traceFile.FullName.Length - lttngExtension.Length) + ".etlx";
Console.WriteLine($"Creating ETLX file {etlFileName} from {traceFile.FullName}");
TraceLog.CreateFromLttngTextDataFile(traceFile.FullName, etlFileName);
}
using (var traceLog = TraceLog.OpenOrConvert(etlFileName))
{
if ((!pid.HasValue && processName == null) && traceLog.Processes.Count != 1)
{
Console.WriteLine("Either a pid or process name from the following list must be specified");
foreach (TraceProcess proc in traceLog.Processes)
{
Console.WriteLine($"Procname = {proc.Name} Pid = {proc.ProcessID}");
}
return(0);
}
if (pid.HasValue && (processName != null))
{
PrintError("--pid and --process-name cannot be specified together");
return(-1);
}
// For a particular process
TraceProcess p;
if (pid.HasValue)
{
p = traceLog.Processes.LastProcessWithID(pid.Value);
}
else if (processName != null)
{
List <TraceProcess> matchingProcesses = new List <TraceProcess>();
foreach (TraceProcess proc in traceLog.Processes)
{
if (String.Compare(proc.Name, processName, StringComparison.OrdinalIgnoreCase) == 0)
{
matchingProcesses.Add(proc);
}
}
if (matchingProcesses.Count == 0)
{
PrintError("Unable to find matching process in trace");
return(-1);
}
if (matchingProcesses.Count > 1)
{
StringBuilder errorMessage = new StringBuilder();
errorMessage.AppendLine("Found multiple matching processes in trace");
foreach (TraceProcess proc in matchingProcesses)
{
errorMessage.AppendLine($"{proc.Name}\tpid={proc.ProcessID}\tCPUMSec={proc.CPUMSec}");
}
PrintError(errorMessage.ToString());
return(-2);
}
p = matchingProcesses[0];
}
else
{
p = traceLog.Processes.First();
}
if (!p.EventsInProcess.ByEventType <MethodDetailsTraceData>().Any())
{
PrintError($"No MethodDetails\nWas the trace collected with provider at least \"Microsoft-Windows-DotNETRuntime:0x4000080018:5\"?");
return(-3);
}
if (!p.EventsInProcess.ByEventType <GCBulkTypeTraceData>().Any())
{
PrintError($"No BulkType data\nWas the trace collected with provider at least \"Microsoft-Windows-DotNETRuntime:0x4000080018:5\"?");
return(-4);
}
if (!p.EventsInProcess.ByEventType <ModuleLoadUnloadTraceData>().Any())
{
PrintError($"No managed module load data\nWas the trace collected with provider at least \"Microsoft-Windows-DotNETRuntime:0x4000080018:5\"?");
return(-5);
}
if (!p.EventsInProcess.ByEventType <MethodJittingStartedTraceData>().Any())
{
PrintError($"No managed jit starting data\nWas the trace collected with provider at least \"Microsoft-Windows-DotNETRuntime:0x4000080018:5\"?");
return(-5);
}
if (processR2REvents)
{
if (!p.EventsInProcess.ByEventType <R2RGetEntryPointTraceData>().Any())
{
PrintError($"No r2r entrypoint data. This is not an error as in this case we can examine the jitted methods only\nWas the trace collected with provider at least \"Microsoft-Windows-DotNETRuntime:0x6000080018:5\"?");
}
}
PgoTraceProcess pgoProcess = new PgoTraceProcess(p);
if (!clrInstanceId.HasValue)
{
HashSet <int> clrInstanceIds = new HashSet <int>();
HashSet <int> examinedClrInstanceIds = new HashSet <int>();
foreach (var assemblyLoadTrace in p.EventsInProcess.ByEventType <AssemblyLoadUnloadTraceData>())
{
if (examinedClrInstanceIds.Add(assemblyLoadTrace.ClrInstanceID))
{
if (pgoProcess.ClrInstanceIsCoreCLRInstance(assemblyLoadTrace.ClrInstanceID))
{
clrInstanceIds.Add(assemblyLoadTrace.ClrInstanceID);
}
}
}
if (clrInstanceIds.Count != 1)
{
if (clrInstanceIds.Count == 0)
{
PrintError($"No managed CLR in target process, or per module information could not be loaded from the trace.");
}
else
{
// There are multiple clr processes... search for the one that implements
int[] clrInstanceIdsArray = clrInstanceIds.ToArray();
Array.Sort(clrInstanceIdsArray);
StringBuilder errorMessage = new StringBuilder();
errorMessage.AppendLine("Multiple CLR instances used in process. Choose one to examine with -clrInstanceID:<id> Valid ids:");
foreach (int instanceID in clrInstanceIds)
{
errorMessage.AppendLine(instanceID.ToString());
}
PrintError(errorMessage.ToString());
}
return(-10);
}
else
{
clrInstanceId = clrInstanceIds.First();
}
}
var tsc = new TraceTypeSystemContext(pgoProcess, clrInstanceId.Value, s_logger);
if (verboseWarnings)
{
Console.WriteLine($"{traceLog.EventsLost} Lost events");
}
bool filePathError = false;
if (reference != null)
{
foreach (FileInfo fileReference in reference)
{
if (!File.Exists(fileReference.FullName))
{
PrintError($"Unable to find reference '{fileReference.FullName}'");
filePathError = true;
}
else
{
tsc.GetModuleFromPath(fileReference.FullName);
}
}
}
if (filePathError)
{
return(-6);
}
if (!tsc.Initialize())
{
return(-12);
}
TraceRuntimeDescToTypeSystemDesc idParser = new TraceRuntimeDescToTypeSystemDesc(p, tsc, clrInstanceId.Value);
SortedDictionary <int, ProcessedMethodData> methodsToAttemptToPrepare = new SortedDictionary <int, ProcessedMethodData>();
if (processR2REvents)
{
foreach (var e in p.EventsInProcess.ByEventType <R2RGetEntryPointTraceData>())
{
int parenIndex = e.MethodSignature.IndexOf('(');
string retArg = e.MethodSignature.Substring(0, parenIndex);
string paramsArgs = e.MethodSignature.Substring(parenIndex);
string methodNameFromEventDirectly = retArg + e.MethodNamespace + "." + e.MethodName + paramsArgs;
if (e.ClrInstanceID != clrInstanceId.Value)
{
if (!warnings)
{
continue;
}
PrintWarning($"Skipped R2REntryPoint {methodNameFromEventDirectly} due to ClrInstanceID of {e.ClrInstanceID}");
continue;
}
MethodDesc method = null;
string extraWarningText = null;
try
{
method = idParser.ResolveMethodID(e.MethodID, verboseWarnings);
}
catch (Exception exception)
{
extraWarningText = exception.ToString();
}
if (method == null)
{
if ((e.MethodNamespace == "dynamicClass") || !warnings)
{
continue;
}
PrintWarning($"Unable to parse {methodNameFromEventDirectly} when looking up R2R methods");
if (extraWarningText != null)
{
PrintWarning(extraWarningText);
}
continue;
}
if ((e.TimeStampRelativeMSec >= excludeEventsBefore) && (e.TimeStampRelativeMSec <= excludeEventsAfter))
{
methodsToAttemptToPrepare.Add((int)e.EventIndex, new ProcessedMethodData(e.TimeStampRelativeMSec, method, "R2RLoad"));
}
}
}
// Find all the jitStart events.
if (processJitEvents)
{
foreach (var e in p.EventsInProcess.ByEventType <MethodJittingStartedTraceData>())
{
int parenIndex = e.MethodSignature.IndexOf('(');
string retArg = e.MethodSignature.Substring(0, parenIndex);
string paramsArgs = e.MethodSignature.Substring(parenIndex);
string methodNameFromEventDirectly = retArg + e.MethodNamespace + "." + e.MethodName + paramsArgs;
if (e.ClrInstanceID != clrInstanceId.Value)
{
if (!warnings)
{
continue;
}
PrintWarning($"Skipped {methodNameFromEventDirectly} due to ClrInstanceID of {e.ClrInstanceID}");
continue;
}
MethodDesc method = null;
string extraWarningText = null;
try
{
method = idParser.ResolveMethodID(e.MethodID, verboseWarnings);
}
catch (Exception exception)
{
extraWarningText = exception.ToString();
}
if (method == null)
{
if (!warnings)
{
continue;
}
PrintWarning($"Unable to parse {methodNameFromEventDirectly}");
if (extraWarningText != null)
{
PrintWarning(extraWarningText);
}
continue;
}
if ((e.TimeStampRelativeMSec >= excludeEventsBefore) && (e.TimeStampRelativeMSec <= excludeEventsAfter))
{
methodsToAttemptToPrepare.Add((int)e.EventIndex, new ProcessedMethodData(e.TimeStampRelativeMSec, method, "JitStart"));
}
}
}
if (displayProcessedEvents)
{
foreach (var entry in methodsToAttemptToPrepare)
{
MethodDesc method = entry.Value.Method;
string reason = entry.Value.Reason;
Console.WriteLine($"{entry.Value.Millisecond.ToString("F4")} {reason} {method}");
}
}
Console.WriteLine($"Done processing input file");
if (outputFileName == null)
{
return(0);
}
// Deduplicate entries
HashSet <MethodDesc> methodsInListAlready = new HashSet <MethodDesc>();
List <ProcessedMethodData> methodsUsedInProcess = new List <ProcessedMethodData>();
foreach (var entry in methodsToAttemptToPrepare)
{
if (methodsInListAlready.Add(entry.Value.Method))
{
methodsUsedInProcess.Add(entry.Value);
}
}
if (pgoFileType.Value == PgoFileType.jittrace)
{
GenerateJittraceFile(outputFileName, methodsUsedInProcess, jitTraceOptions);
}
else if (pgoFileType.Value == PgoFileType.mibc)
{
return(GenerateMibcFile(tsc, outputFileName, methodsUsedInProcess, validateOutputFile));
}
}
return(0);
}
static void GenerateJittraceFile(FileInfo outputFileName, IEnumerable <ProcessedMethodData> methodsToAttemptToPrepare, jittraceoptions jittraceOptions)
{
s_logger.PrintMessage($"JitTrace options {jittraceOptions}");
List <string> methodsToPrepare = new List <string>();
HashSet <string> prepareMethods = new HashSet <string>();
Dictionary <TypeDesc, string> typeStringCache = new Dictionary <TypeDesc, string>();
StringBuilder methodPrepareInstruction = new StringBuilder();
StringBuilder instantiationBuilder = new StringBuilder();
const string outerCsvEscapeChar = "~";
const string innerCsvEscapeChar = ":";
foreach (var entry in methodsToAttemptToPrepare)
{
MethodDesc method = entry.Method;
string reason = entry.Reason;
double time = entry.Millisecond;
methodPrepareInstruction.Clear();
instantiationBuilder.Clear();
// Format is FriendlyNameOfMethod~typeIndex~ArgCount~GenericParameterCount:genericParamsSeperatedByColons~MethodName
// This format is not sufficient to exactly describe methods, so the runtime component may compile similar methods
// In the various strings \ is escaped to \\ and in the outer ~ csv the ~ character is escaped to \s. In the inner csv : is escaped to \s
try
{
string timeStampAddon = "";
if (jittraceOptions.HasFlag(jittraceoptions.showtimestamp))
{
timeStampAddon = time.ToString("F4") + "-";
}
methodPrepareInstruction.Append(CsvEscape(timeStampAddon + method.ToString(), outerCsvEscapeChar));
methodPrepareInstruction.Append(outerCsvEscapeChar);
methodPrepareInstruction.Append(CsvEscape(GetStringForType(method.OwningType, typeStringCache), outerCsvEscapeChar));
methodPrepareInstruction.Append(outerCsvEscapeChar);
methodPrepareInstruction.Append(method.Signature.Length);
methodPrepareInstruction.Append(outerCsvEscapeChar);
instantiationBuilder.Append(method.Instantiation.Length);
foreach (TypeDesc methodInstantiationType in method.Instantiation)
{
instantiationBuilder.Append(innerCsvEscapeChar);
instantiationBuilder.Append(CsvEscape(GetStringForType(methodInstantiationType, typeStringCache), innerCsvEscapeChar));
}
methodPrepareInstruction.Append(CsvEscape(instantiationBuilder.ToString(), outerCsvEscapeChar));
methodPrepareInstruction.Append(outerCsvEscapeChar);
methodPrepareInstruction.Append(CsvEscape(method.Name, outerCsvEscapeChar));
}
catch (Exception ex)
{
PrintWarning($"Exception {ex} while attempting to generate method lists");
continue;
}
string prepareInstruction = methodPrepareInstruction.ToString();
if (!prepareMethods.Contains(prepareInstruction))
{
prepareMethods.Add(prepareInstruction);
methodsToPrepare.Add(prepareInstruction);
}
}
if (jittraceOptions.HasFlag(jittraceoptions.sorted))
{
methodsToPrepare.Sort();
}
using (TextWriter tw = new StreamWriter(outputFileName.FullName))
{
foreach (string methodString in methodsToPrepare)
{
tw.WriteLine(methodString);
}
}
Console.WriteLine($"Generated {outputFileName.FullName}");
}
void DefineArgumentSyntax(ArgumentSyntax syntax)
{
bool activeCommandIsCommandAssociatedWithTraceProcessing = false;
syntax.ApplicationName = typeof(Program).Assembly.GetName().Name.ToString();
// HandleHelp writes to error, fails fast with crash dialog and lacks custom formatting.
syntax.HandleHelp = false;
syntax.HandleErrors = false;
string command = "";
void CommonOptions()
{
string traceFile = null;
syntax.DefineOption(
name: "t|trace",
value: ref traceFile,
help: "Specify the trace file to be parsed.",
requireValue: true);
if (traceFile != null)
{
TraceFile = new FileInfo(traceFile);
}
OutputOption();
int pidLocal = 0;
if (syntax.DefineOption(
name: "pid",
value: ref pidLocal,
help: "The pid within the trace of the process to examine. If this is a multi-process trace, at least one of --pid or --process-name must be specified",
requireValue: true).IsSpecified)
{
Pid = pidLocal;
}
syntax.DefineOption(
name: "process-name",
value: ref ProcessName,
help: "The process name within the trace of the process to examine. If this is a multi-process trace, at least one of --pid or --process-name must be specified.",
requireValue: false);
int clrInstanceIdLocal = 0;
if (syntax.DefineOption(
name: "clr-instance-id",
value: ref clrInstanceIdLocal,
help: "If the process contains multiple .NET runtimes, the instance ID must be specified.",
requireValue: true).IsSpecified)
{
ClrInstanceId = clrInstanceIdLocal;
}
Reference = DefineFileOptionList(name: "r|reference", help: "If a reference is not located on disk at the same location as used in the process, it may be specified with a --reference parameter. Multiple --reference parameters may be specified. The wild cards * and ? are supported by this option.");
ExcludeEventsBefore = Double.MinValue;
syntax.DefineOption(
name: "exclude-events-before",
value: ref ExcludeEventsBefore,
help: "Exclude data from events before specified time. Time is specified as milliseconds from the start of the trace.",
valueConverter: Convert.ToDouble,
requireValue: true);
ExcludeEventsAfter = Double.MaxValue;
syntax.DefineOption(
name: "exclude-events-after",
value: ref ExcludeEventsAfter,
help: "Exclude data from events after specified time. Time is specified as milliseconds from the start of the trace.",
valueConverter: Convert.ToDouble,
requireValue: true);
VerbosityOption();
}
void OutputOption()
{
string outputFile = null;
syntax.DefineOption(
name: "o|output",
value: ref outputFile,
help: "Specify the output filename to be created.",
requireValue: true);
if (outputFile != null)
{
OutputFileName = new FileInfo(outputFile);
}
}
void VerbosityOption()
{
Verbosity verbosity = Verbosity.normal;
syntax.DefineOption(name: "v|verbosity", value: ref verbosity, help: "Adjust verbosity level. Supported levels are minimal, normal, detailed, and diagnostic.", valueConverter: VerbosityConverter, requireValue: true);
BasicProgressMessages = (int)verbosity >= (int)Verbosity.normal;
Warnings = (int)verbosity >= (int)Verbosity.normal;
VerboseWarnings = (int)verbosity >= (int)Verbosity.detailed;
DetailedProgressMessages = (int)verbosity >= (int)Verbosity.detailed;
DisplayProcessedEvents = (int)verbosity >= (int)Verbosity.diagnostic;
}
void CompressedOption()
{
bool compressed = false;
syntax.DefineOption(name: "compressed", value: ref compressed, help: "Generate compressed mibc", requireValue: false);
Uncompressed = !compressed;
}
void HelpOption()
{
syntax.DefineOption("h|help", ref Help, "Display this usage message.");
}
var mibcCommand = syntax.DefineCommand(name: "create-mibc", value: ref command, help: "Transform a trace file into a Mibc profile data file.");
if (mibcCommand.IsActive)
{
activeCommandIsCommandAssociatedWithTraceProcessing = true;
HelpArgs = new string[] { "create-mibc", "--help", "--trace", "trace", "--output", "output" };
FileType = PgoFileType.mibc;
GenerateCallGraph = true;
ProcessJitEvents = true;
ProcessR2REvents = true;
#if DEBUG
ValidateOutputFile = true;
#else
ValidateOutputFile = false;
#endif
CommonOptions();
CompressedOption();
HelpOption();
}
JitTraceOptions = jittraceoptions.none;
#if DEBUG
// Usage of the jittrace format requires using logic embedded in the runtime repository and isn't suitable for general consumer use at this time
// Build it in debug and check builds to ensure that it doesn't bitrot, and remains available for use by developers willing to build the repo
var jittraceCommand = syntax.DefineCommand(name: "create-jittrace", value: ref command, help: "Transform a trace file into a jittrace runtime file.");
if (jittraceCommand.IsActive)
{
activeCommandIsCommandAssociatedWithTraceProcessing = true;
HelpArgs = new string[] { "create-jittrace", "--help", "--trace", "trace", "--output", "output" };
FileType = PgoFileType.jittrace;
ProcessJitEvents = true;
ProcessR2REvents = false;
ValidateOutputFile = false;
CommonOptions();
bool sorted = false;
syntax.DefineOption(name: "sorted", value: ref sorted, help: "Generate sorted output.", requireValue: false);
if (sorted)
{
JitTraceOptions |= jittraceoptions.sorted;
}
bool showtimestamp = false;
syntax.DefineOption(name: "showtimestamp", value: ref showtimestamp, help: "Show timestamps in output.", requireValue: false);
if (showtimestamp)
{
JitTraceOptions |= jittraceoptions.showtimestamp;
}
syntax.DefineOption(name: "includeReadyToRun", value: ref ProcessR2REvents, help: "Include ReadyToRun methods in the trace file.", requireValue: false);
HelpOption();
}
#endif
var mergeCommand = syntax.DefineCommand(name: "merge", value: ref command, help: "Merge multiple Mibc profile data files into one file.");
if (mergeCommand.IsActive)
{
HelpArgs = new string[] { "merge", "--help", "--output", "output", "--input", "input" };
InputFilesToMerge = DefineFileOptionList(name: "i|input", help: "If a reference is not located on disk at the same location as used in the process, it may be specified with a --reference parameter. Multiple --reference parameters may be specified. The wild cards * and ? are supported by this option.");
OutputOption();
IReadOnlyList <string> assemblyNamesAsStrings = null;
syntax.DefineOptionList(name: "include-reference", value: ref assemblyNamesAsStrings, help: "If specified, include in Mibc file only references to the specified assemblies. Assemblies are specified as assembly names, not filenames. For instance, `System.Private.CoreLib` not `System.Private.CoreLib.dll`. Multiple --include-reference options may be specified.", requireValue: true);
if (assemblyNamesAsStrings != null)
{
foreach (string asmName in assemblyNamesAsStrings)
{
try
{
IncludedAssemblies.Add(new AssemblyName(asmName));
}
catch
{
throw new FormatException($"Unable to parse '{asmName}' as an Assembly Name.");
}
}
}
VerbosityOption();
CompressedOption();
HelpOption();
#if DEBUG
ValidateOutputFile = true;
#else
ValidateOutputFile = false;
#endif
}
var dumpCommand = syntax.DefineCommand(name: "dump", value: ref command, help: "Dump the contents of a Mibc file.");
if (dumpCommand.IsActive)
{
DumpMibc = true;
HelpArgs = new string[] { "dump", "--help", "input", "output" };
VerbosityOption();
HelpOption();
string inputFileToDump = null;
syntax.DefineParameter(name: "input", ref inputFileToDump, "Name of the input mibc file to dump.");
if (inputFileToDump != null)
{
InputFileToDump = new FileInfo(inputFileToDump);
}
string outputFile = null;
syntax.DefineParameter(name: "output", ref outputFile, "Name of the output dump file.");
if (outputFile != null)
{
OutputFileName = new FileInfo(outputFile);
}
}
if (syntax.ActiveCommand == null)
{
// No command specified
Help = true;
}
if (activeCommandIsCommandAssociatedWithTraceProcessing)
{
HelpText =
@$ "{syntax.GetHelpText()}
Example tracing commands used to generate the input to this tool:
" "dotnet-trace collect -p 73060 --providers Microsoft-Windows-DotNETRuntime:0x1E000080018:4" "
- Capture events from process 73060 where we capture both JIT and R2R events using EventPipe tracing
" "dotnet-trace collect -p 73060 --providers Microsoft-Windows-DotNETRuntime:0x1C000080018:4" "
- Capture events from process 73060 where we capture only JIT events using EventPipe tracing
" "perfview collect -LogFile:logOfCollection.txt -DataFile:jittrace.etl -Zip:false -merge:false -providers:Microsoft-Windows-DotNETRuntime:0x1E000080018:4" "
- Capture Jit and R2R events via perfview of all processes running using ETW tracing
";
}
else
{
HelpText = syntax.GetHelpText();
}
List <FileInfo> DefineFileOptionList(string name, string help)
{
IReadOnlyList <string> filesAsStrings = null;
syntax.DefineOptionList(name: name, value: ref filesAsStrings, help: help, requireValue: true);
List <FileInfo> referenceList = new List <FileInfo>();
if (filesAsStrings != null)
{
foreach (string pattern in filesAsStrings)
{
Dictionary <string, string> paths = new Dictionary <string, string>(StringComparer.OrdinalIgnoreCase);
Helpers.AppendExpandedPaths(paths, pattern, false);
foreach (string file in paths.Values)
{
referenceList.Add(new FileInfo(file));
}
}
}
return(referenceList);
}
}
